OSIV 해결하기

문제점

Constroller에서 Lazy Loading이 실패하고 no Session 에러 발생

문제진단

현재 open in view 옵션은 기본값인 true이다

즉, 원래라면 open in view가 동작하는 것이 맞다

하지만 실제로 영속석 컨텍스트가 열리는 곳은 @Transactional 어노테이션이 붙은 곳 부터 시작한다

1. 컨트롤러 시작
2. 영속성 컨텍스트(=세션) 오픈
3. 트랜잭션 시작
4. 서비스 진입
5. 서비스 반환 전
6. 영속성 컨텍스트(=세션) 닫음
7. 컨트롤러 재진입

a.a.b.d.conversion.InspectionFeedbackController [findByInspector] - =====>> 검수 컨트롤러 시작
org.hibernate.internal.SessionImpl [<init>] - Opened Session [bc7499af-8f52-4cfa-902f-ae0256591460] at timestamp: 16414363084 // 영속성 컨텍스트 open
o.h.engine.transaction.internal.TransactionImpl [begin] - begin // 트랜잭션 시작

a.a.b.domain.conversion.InspectionFeedbackService [find] - =====>>> 검수 서비스 검색
o.h.engine.transaction.internal.TransactionImpl [commit] - committing // 커밋 완료
org.hibernate.internal.SessionImpl [close] - Closing session [bc7499af-8f52-4cfa-902f-ae0256591460] // 영속성 컨텍스트 close

a.a.b.d.conversion.InspectionFeedbackController [findByInspector] - =====>> 검수 서비스 반환

즉, open in view가 제대로 동작하지 않고

@Transactional 어노테이션을 가진 메소드 범위에서 영속성 컨텍스트를 열고 닫게 된다

그러므로 Controller까지 영속성 컨텍스트(세션)가 열려 있지 않으므로

영속성 컨텍스트가 detach된 상태이므로 Controller에서는 Lazy Loading이 되지 않아 no Session 에러를 반환한다

Open Session In View 구조

OSIV가 정상적으로 동작을 하면 OSIV가 true일 때 Member 저장 요청 시 다음과 같이 동작한다

1. OpenEntityManagerInViewInterceptor에서 영속성 컨텍스트를 Open
2. @Transactional 어노테이션이 붙은 메소드에서 트랜잭션이 시작
3. @Transactional 어노테이션이 붙은 메소드가 종료되면 트랜잭션이 종료
4. OpenEntityManagerInViewInterceptor에서 영속성 컨텍스트를 Close

o.s.b.w.s.f.OrderedRequestContextFilter  : Bound request context to thread: org.apache.catalina.connector.RequestFacade@69d1118d
o.s.web.servlet.DispatcherServlet        : POST "/members", parameters={}, headers={masked} in DispatcherServlet 'dispatcherServlet'
o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'memberController'
s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.bgpark.osiv.domain.MemberController#save()
o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor // 영속성 컨텍스트(=세션) 오픈
o.s.web.method.HandlerMethod             : Arguments: []
o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(2135179516<open>)] for JPA transaction
o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT // @Transactional 어노테이션이 붙은 메소드에서 트랜잭션 생성
o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@7183a164]
o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit // @Transactional 어노테이션이 붙은 메소드 종료 시 트랜잭션 종료
o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(2135179516<open>)]
o.s.orm.jpa.JpaTransactionManager        : Not closing pre-bound JPA EntityManager after transaction
m.m.a.RequestResponseBodyMethodProcessor : Using 'application/json', given [*/*] and supported [application/json, application/*+json, application/json, application/*+json]
m.m.a.RequestResponseBodyMethodProcessor : Writing [com.bgpark.osiv.domain.Member@75bc2b8c]
s.w.s.m.m.a.RequestMappingHandlerAdapter : Applying default cacheSeconds=-1
o.s.web.servlet.DispatcherServlet        : No view rendering, null ModelAndView returned.
o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor // 영속성 컨텍스트(=세션) 닫음
o.s.web.servlet.DispatcherServlet        : Completed 200 OK, headers={masked}
o.s.b.w.s.f.OrderedRequestContextFilter  : Cleared thread-bound request context: org.apache.catalina.connector.RequestFacade@69d1118d

즉, OpenEntityManagerInViewInterceptor가 각 Controller에 도달하기 전 미리 영속성 컨텍스트를 열어 놓는다

서비스에서는 트랜잭션 작업과 영속성 컨텍스트를 flush까지 한다

다시 컨트롤러로 돌아왔을 때는 아직 영속성 컨텍스트가 닫히지 않았으므로 Lazy Loading이 가능하다

Controller에서 View를 거쳐 다시 OpenEntityManagerInViewInterceptor로 돌아오면 그때 영속성 컨텍스트를 닫는다

Open Session In View 동작과정

클라이언트가 url 요청 이후

OpenEntityManagerInViewInterceptor

JpaWebMvcConfiguration

• 스프링 구동 시, application.properties에서 spring.jpa.open-in-view: true이면
• JpaWebMvcConfiguration에서 OpenEntityManagerInViewInterceptor을 등록한다
• 하지만 interceptor 자체가 등록이 안되는 상태

@Configuration
@ConditionalOnWebApplication(type = Type.SERVLET) // 웹인 경우 실행
@ConditionalOnClass(WebMvcConfigurer.class) // WebConfigurer인 경우 실행
@ConditionalOnMissingBean({ 
    OpenEntityManagerInViewInterceptor.class, // OpenEntityManagerInViewInterceptor 빈이 없는 경우 실행
        OpenEntityManagerInViewFilter.class })
@ConditionalOnProperty(prefix = "spring.jpa", name = "open-in-view", havingValue = "true", matchIfMissing = true)
protected static class JpaWebConfiguration {

    // Defined as a nested config to ensure WebMvcConfigurerAdapter is not read when
    // not on the classpath
    @Configuration
    protected static class JpaWebMvcConfiguration implements WebMvcConfigurer {

        private static final Log logger = LogFactory
                .getLog(JpaWebMvcConfiguration.class);

        private final JpaProperties jpaProperties;

        protected JpaWebMvcConfiguration(JpaProperties jpaProperties) {
            this.jpaProperties = jpaProperties;
        }

        @Bean
        public OpenEntityManagerInViewInterceptor openEntityManagerInViewInterceptor() {
            if (this.jpaProperties.getOpenInView() == null) {
                logger.warn("spring.jpa.open-in-view is enabled by default. "
                        + "Therefore, database queries may be performed during view "
                        + "rendering. Explicitly configure "
                        + "spring.jpa.open-in-view to disable this warning");
            }
            return new OpenEntityManagerInViewInterceptor();
        }

        @Override
        public void addInterceptors(InterceptorRegistry registry) {
            registry.addWebRequestInterceptor(openEntityManagerInViewInterceptor());
        }

}

}

1. Interceptor에서 request를 preHandler가 받는다
2. 첫번째 요청인 경우
3. EntityManagerFactory(=LocalContainerEntityManagerFactoryBean)에서 EntityManager(=SessionImpl)를 생성한다
4. EntityManager를 EntityManagerHolder에 넣는다
5. EntityManagerFactory를 key로 EntityManager를 value로 저장한다
   • 여기서 EntityManagerFactory를 Resource라고 부른다
   • 이 작업을 Resource를 binding한다고 한다

@Override
public void preHandle(WebRequest request) throws DataAccessException {  // request를 핸들링
  ...

    EntityManagerFactory emf = obtainEntityManagerFactory();   // 엔티티 매니저 생성

    // 1. LocalContainerEntityManagerFactoryBean를 키로 가진 EntityManager 있는지 확인
    if (TransactionSynchronizationManager.hasResource(emf)) {
            ...
    }
    // 2. 첫 요청인 경우
    else {
        logger.debug("Opening JPA EntityManager in OpenEntityManagerInViewInterceptor");
        try {
            // LocalContainerEntityManagerFactoryBean으로 부터 EntityManager 생성
            EntityManager em = createEntityManager();
            // EntityManager를 EntityManagerHolder에 저장
            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);
        }
    }
}

1. EntityManagerFactory(=LocalContainerEntityManagerFactoryBean)에서 EntityManager(=SessionImpl)를 생성한다 의 자세한 설명
   1. LocalContainerEntityManagerFactoryBean는 프록시다
   2. LocalContainerEntityManagerFactoryBean.createEntityManager()를 호출하면
   3. AbstractEntityManagerBean에서 invokeProxyMethod를 호출한다

Object invokeProxyMethod(Method method, @Nullable Object[] args) throws Throwable {
        ...

        // Standard delegation to the native factory, just post-processing EntityManager return values
        Object retVal = method.invoke(getNativeEntityManagerFactory(), args); // SessionFactoryImpl로 EntityManager를 반환 = SessionImpl
        if (retVal instanceof EntityManager) {
            // Any other createEntityManager variant - expecting non-synchronized semantics
            EntityManager rawEntityManager = (EntityManager) retVal; 
            postProcessEntityManager(rawEntityManager); 
            retVal = ExtendedEntityManagerCreator.createApplicationManagedEntityManager(rawEntityManager, this, false);
        }
        return retVal;
    }

SessionFactoryImpl로 EntityManager 생성과정

1. 영속성 컨텍스트가 자동으로 DB와 동기화 할 것인지
2. session이 밖으로 나가는 트랜잭션에 자동으로 조인 여부
3. openSession으로 SessionImpl 생성

private <K,V> Session buildEntityManager(final SynchronizationType synchronizationType, final Map<K,V> map) {
        assert status != Status.CLOSED;

        SessionBuilderImplementor builder = withOptions();
        if ( synchronizationType == SynchronizationType.SYNCHRONIZED ) { // 영속성 컨텍스트가 자동으로 DB와 동기화 할 것인지
            builder.autoJoinTransactions( true ); // session이 밖으로 나가는 트랜잭션에 자동으로 조인 여부
        }
        ...
        final Session session = builder.openSession();
        ...
        return session;
    }

    @Override
    public Session openSession() {
        log.tracef( "Opening Hibernate Session.  tenant=%s", tenantIdentifier );
        return new SessionImpl( sessionFactory, this );
    }

SessionImpl(=EntityManager) 생성 과정

1. PersistenceContext (=StatefulPersistenceContext) 생성
2. PersistenceContext는 SessionImpl(=EntityManager)와 PersistenceContext를 확장한 EntityEntryContext를 가진다
   • EntityEntryContext가 우리가 흔히 이야기하는 PersistenceContext의 구현체로 추정된다
3. flushMode를 auto로 설정한다

public SessionImpl(SessionFactoryImpl factory, SessionCreationOptions options) {
        super( factory, options );

        this.persistenceContext = createPersistenceContext(); // PersistenceContext 생성
        this.actionQueue = createActionQueue();

        this.autoClear = options.shouldAutoClear(); 
        this.autoClose = options.shouldAutoClose();
        this.queryParametersValidationEnabled = options.isQueryParametersValidationEnabled();
        ...

        if ( this.properties == null ) {
            initialMode = fastSessionServices.initialSessionFlushMode; // flushMode를 auto로 설정한다
        }
        ...


    }

컨트롤러에서 종료 이후

OpenEntityManagerInViewInterceptor

• Resource(=EntityManagerFactory)를 EntityManager에서 unbind한다
• EntityManager(=SessionImpl)을 close 한다
  • 이 때, 영속성 컨텍스트에서 persistent된 엔티티가 detached 된다
  • 즉, OSIV는 Interceptor까지 영속성 컨텍스트를 유지한다

@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());
        }
    }

상세로그

1. Session 오픈
2. Transaction 시작
3. JDBC 커넥션 호출
4. SQL 작성
5. SQL 실행
6. Transaction 커밋
7. EntityManager를 flush
8. JDBC 커넥션 반환
9. Session를 close

o.s.b.w.s.f.OrderedRequestContextFilter  : Bound request context to thread: org.apache.catalina.connector.RequestFacade@32a29000
o.s.web.servlet.DispatcherServlet        : POST "/members", parameters={}, headers={masked} in DispatcherServlet 'dispatcherServlet'
o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'memberController'
s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.bgpark.osiv.domain.MemberController#save()

1. EntityManager(=Session)를 Open
2. Transaction(=JpaTransaction)을 생성
3. Transaction을 시작

o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor // OSVI에서 EntityManager를 Open
.i.SessionFactoryImpl$SessionBuilderImpl : Opening Hibernate Session.  tenant=null
org.hibernate.internal.SessionImpl       : Opened Session [d397a4cc-f302-4b9c-bb5b-dd8eac60b7dc] at timestamp: 1641398043450
o.s.web.method.HandlerMethod             : Arguments: []
o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(1112566729PersistenceContext[entityKeys=[], collectionKeys=[]];ActionQueue[insertions=ExecutableList{size=0} updates=ExecutableList{size=0} deletions=ExecutableList{size=0} orphanRemovals=ExecutableList{size=0} collectionCreations=ExecutableList{size=0} collectionRemovals=ExecutableList{size=0} collectionUpdates=ExecutableList{size=0} collectionQueuedOps=ExecutableList{size=0} unresolvedInsertDependencies=null])] for JPA transaction
o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
o.h.e.t.internal.TransactionImpl         : On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
o.h.e.t.internal.TransactionImpl         : begin

4. JDBC 커넥션에 의한 트랜잭션 시작

j.i.AbstractLogicalConnectionImplementor : Preparing to begin transaction via JDBC Connection.setAutoCommit(false)
j.i.AbstractLogicalConnectionImplementor : Transaction begun via JDBC Connection.setAutoCommit(false)
cResourceLocalTransactionCoordinatorImpl : ResourceLocalTransactionCoordinatorImpl#afterBeginCallback
o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@4c979df3]
o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
o.hibernate.event.internal.EntityState   : Transient instance of: com.bgpark.osiv.domain.Member
o.h.e.i.DefaultPersistEventListener      : Saving transient instance
o.h.e.i.AbstractSaveEventListener        : Saving [com.bgpark.osiv.domain.Member#<null>]
org.hibernate.engine.spi.ActionQueue     : Adding an EntityIdentityInsertAction for [com.bgpark.osiv.domain.Member] object
org.hibernate.engine.spi.ActionQueue     : Executing inserts before finding non-nullable transient entities for early insert: [EntityIdentityInsertAction[com.bgpark.osiv.domain.Member#<null>]]
org.hibernate.engine.spi.ActionQueue     : Adding insert with no non-nullable, transient entities: [EntityIdentityInsertAction[com.bgpark.osiv.domain.Member#<null>]]
org.hibernate.engine.spi.ActionQueue     : Executing insertions before resolved early-insert
org.hibernate.engine.spi.ActionQueue     : Executing identity-insert immediately

5. SQL 생성
6. HikariProxyPreparedStatement에 구문 저장
7. 파라미터 바인딩
8. ResultSet 생성
8. ResultSet 종료
8. statement를 execute

o.h.p.entity.AbstractEntityPersister     : Inserting entity: com.bgpark.osiv.domain.Member (native id)
org.hibernate.SQL                        : insert into member (id, name) values (null, ?)
o.h.r.j.i.ResourceRegistryStandardImpl   : Registering statement [HikariProxyPreparedStatement@229283784 wrapping prep2: insert into member (id, name) values (null, ?)]
o.h.p.entity.AbstractEntityPersister     : Dehydrating entity: [com.bgpark.osiv.domain.Member#<null>]
o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [박병길]
o.h.id.IdentifierGeneratorHelper         : Natively generated identity: 2
o.h.r.j.i.ResourceRegistryStandardImpl   : Releasing result set [HikariProxyResultSet@1281731479 wrapping rs4: org.h2.result.LocalResultImpl@3c6ddfed columns: 1 rows: 1 pos: 0]
o.h.r.j.i.ResourceRegistryStandardImpl   : Closing result set [HikariProxyResultSet@1281731479 wrapping rs4: org.h2.result.LocalResultImpl@3c6ddfed columns: 1 rows: 1 pos: 0]
o.h.r.j.i.ResourceRegistryStandardImpl   : Releasing statement [HikariProxyPreparedStatement@229283784 wrapping prep2: insert into member (id, name) values (null, ?) {1: STRINGDECODE('\ubc15\ubcd1\uae38')}]
o.h.r.j.i.ResourceRegistryStandardImpl   : HHH000387: ResultSet's statement was not registered
o.h.r.j.i.ResourceRegistryStandardImpl   : Closing prepared statement [HikariProxyPreparedStatement@229283784 wrapping prep2: insert into member (id, name) values (null, ?) {1: STRINGDECODE('\ubc15\ubcd1\uae38')}]
o.h.e.jdbc.internal.JdbcCoordinatorImpl  : Starting after statement execution processing [ON_CLOSE]

11. EntityManager의 Transaction를 commit
12. EntityManager를 flush

o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(1112566729PersistenceContext[entityKeys=[EntityKey[com.bgpark.osiv.domain.Member#2]], collectionKeys=[]];ActionQueue[insertions=ExecutableList{size=0} updates=ExecutableList{size=0} deletions=ExecutableList{size=0} orphanRemovals=ExecutableList{size=0} collectionCreations=ExecutableList{size=0} collectionRemovals=ExecutableList{size=0} collectionUpdates=ExecutableList{size=0} collectionQueuedOps=ExecutableList{size=0} unresolvedInsertDependencies=null])]
o.h.e.t.internal.TransactionImpl         : committing
cResourceLocalTransactionCoordinatorImpl : ResourceLocalTransactionCoordinatorImpl#beforeCompletionCallback
org.hibernate.internal.SessionImpl       : SessionImpl#beforeTransactionCompletion()
org.hibernate.internal.SessionImpl       : Automatically flushing session
o.h.e.i.AbstractFlushingEventListener    : Flushing session
o.h.e.i.AbstractFlushingEventListener    : Processing flush-time cascades
org.hibernate.engine.internal.Cascade    : Processing cascade ACTION_PERSIST_ON_FLUSH for: com.bgpark.osiv.domain.Member
org.hibernate.engine.internal.Cascade    : Done processing cascade ACTION_PERSIST_ON_FLUSH for: com.bgpark.osiv.domain.Member
o.h.e.i.AbstractFlushingEventListener    : Dirty checking collections
o.h.e.i.AbstractFlushingEventListener    : Flushing entities and processing referenced collections
o.h.e.i.AbstractFlushingEventListener    : Processing unreferenced collections
o.h.e.i.AbstractFlushingEventListener    : Scheduling collection removes/(re)creates/updates
o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
o.hibernate.internal.util.EntityPrinter  : Listing entities:
o.hibernate.internal.util.EntityPrinter  : com.bgpark.osiv.domain.Member{name=박병길, id=2}
o.h.e.i.AbstractFlushingEventListener    : Executing flush

o.h.e.jdbc.internal.JdbcCoordinatorImpl  : Starting after statement execution processing [ON_CLOSE]
o.h.e.i.AbstractFlushingEventListener    : Post flush
j.i.AbstractLogicalConnectionImplementor : LogicalConnection#beforeTransactionCompletion
.t.i.SynchronizationRegistryStandardImpl : SynchronizationRegistryStandardImpl.notifySynchronizationsBeforeTransactionCompletion
j.i.AbstractLogicalConnectionImplementor : Preparing to commit transaction via JDBC Connection.commit()
j.i.AbstractLogicalConnectionImplementor : Transaction committed via JDBC Connection.commit()
j.i.AbstractLogicalConnectionImplementor : re-enabling auto-commit on JDBC Connection after completion of JDBC-based transaction
j.i.AbstractLogicalConnectionImplementor : LogicalConnection#afterTransaction
o.h.r.j.i.ResourceRegistryStandardImpl   : Releasing JDBC resources

14. HTTP 응답
15. JDBC 커넥션 반환
16. OSIV에서 EntityManager를 close - 이때 영속성 컨텍스트는 detach, 커넥션이 반환되어도 close가 되어야 영속성 컨텍스트가 detach된다

cResourceLocalTransactionCoordinatorImpl : ResourceLocalTransactionCoordinatorImpl#afterCompletionCallback(true)
.t.i.SynchronizationRegistryStandardImpl : SynchronizationRegistryStandardImpl.notifySynchronizationsAfterTransactionCompletion(3)
org.hibernate.internal.SessionImpl       : SessionImpl#afterTransactionCompletion(successful=true, delayed=false)
o.s.orm.jpa.JpaTransactionManager        : Not closing pre-bound JPA EntityManager after transaction
m.m.a.RequestResponseBodyMethodProcessor : Using 'application/json', given [*/*] and supported [application/json, application/*+json, application/json, application/*+json]
m.m.a.RequestResponseBodyMethodProcessor : Writing [com.bgpark.osiv.domain.MemberDto@3448bd11]
s.w.s.m.m.a.RequestMappingHandlerAdapter : Applying default cacheSeconds=-1
o.s.web.servlet.DispatcherServlet        : No view rendering, null ModelAndView returned.
o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
org.hibernate.internal.SessionImpl       : Closing session [d397a4cc-f302-4b9c-bb5b-dd8eac60b7dc]
o.h.e.jdbc.internal.JdbcCoordinatorImpl  : Closing JDBC container [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl@6d856887]
o.h.r.j.i.ResourceRegistryStandardImpl   : Releasing JDBC resources
o.h.r.j.i.LogicalConnectionManagedImpl   : Closing logical connection
o.h.r.j.i.ResourceRegistryStandardImpl   : Releasing JDBC resources
o.h.r.j.i.LogicalConnectionManagedImpl   : Logical connection closed
o.s.web.servlet.DispatcherServlet        : Completed 200 OK, headers={masked}
o.s.b.w.s.f.OrderedRequestContextFilter  : Cleared thread-bound request context: org.apache.catalina.connector.RequestFacade@32a29000

스프링 서큐리티와의 관계

기본적으로 스프링 서큐리티는 Filter로 동작을 한다

해결

OpenEntityManagerInViewFilter를 등록한다

• DispatcherServlet 전에 Filter에서 Session을 열고 닫는다.

@Component
@Configuration
public class OpenEntityManagerConfig {
    @Bean
    public FilterRegistrationBean<OpenEntityManagerInViewFilter> openEntityManagerInViewFilter() {
        FilterRegistrationBean<OpenEntityManagerInViewFilter> filterFilterRegistrationBean = new FilterRegistrationBean<>();
        filterFilterRegistrationBean.setFilter(new OpenEntityManagerInViewFilter());
        filterFilterRegistrationBean.setOrder(Integer.MIN_VALUE); // 예시를 위해 최우선 순위로 Filter 등록
        return filterFilterRegistrationBean;
    }
}

1. OpenEntityManagerInViewFilter에서 EntityManager 오픈
2. 서비스 진입
3. 트랜잭션 시작 
4. 쿼리 작성
5. 트랜잭션 커밋
6. 서비스 반환
7. 컨트롤러 복귀
9. dto 매핑 
10. OpenEntityManagerInViewFilter에서 EntityManager 클로즈

o.s.orm.jpa.support.OpenEntityManagerInViewFilter [doFilterInternal] - Opening JPA EntityManager in OpenEntityManagerInViewFilter
o.h.internal.SessionFactoryImpl$SessionBuilderImpl [openSession] - Opening Hibernate Session.  tenant=null, owner=null
o.h.r.jdbc.internal.LogicalConnectionManagedImpl [<init>] - `hibernate.connection.provider_disables_autocommit` was enabled.  This setting should only be enabled when you are certain that the Connections given to Hibernate by the ConnectionProvider have auto-commit disabled.  Enabling this setting when the Connections do not have auto-commit disabled will lead to Hibernate executing SQL operations outside of any JDBC/SQL transaction.
org.hibernate.internal.SessionImpl [<init>] - Opened Session [466b0bdf-35c7-4512-9bce-44fff361a733] at timestamp: 16414383059
a.a.b.d.conversion.InspectionFeedbackController [findByInspector] - =====>> 서비스 호출 전
o.h.engine.transaction.internal.TransactionImpl [begin] - begin
o.h.r.t.b.j.i.JdbcResourceLocalTransactionCoordinatorImpl [afterBeginCallback] - ResourceLocalTransactionCoordinatorImpl#afterBeginCallback
o.h.event.internal.DefaultLoadEventListener [proxyOrLoad] - Loading entity: [ai.alethio.babyface.domain.conversion.InspectionFeedback#1]
o.h.event.internal.DefaultLoadEventListener [createProxyIfNecessary] - Creating new proxy for entity
o.h.engine.transaction.internal.TransactionImpl [commit] - committing
o.h.r.t.b.j.i.JdbcResourceLocalTransactionCoordinatorImpl [beforeCompletionCallback] - ResourceLocalTransactionCoordinatorImpl#beforeCompletionCallback
org.hibernate.internal.SessionImpl [beforeTransactionCompletion] - SessionImpl#beforeTransactionCompletion()
o.h.r.t.i.SynchronizationRegistryStandardImpl [notifySynchronizationsBeforeTransactionCompletion] - SynchronizationRegistryStandardImpl.notifySynchronizationsBeforeTransactionCompletion
o.h.r.j.i.AbstractLogicalConnectionImplementor [commit] - Preparing to commit transaction via JDBC Connection.commit()
o.h.r.j.i.AbstractLogicalConnectionImplementor [commit] - Transaction committed via JDBC Connection.commit()
o.h.r.j.i.AbstractLogicalConnectionImplementor [afterTransaction] - LogicalConnection#afterTransaction
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [releaseResources] - Releasing JDBC resources
o.h.r.t.b.j.i.JdbcResourceLocalTransactionCoordinatorImpl [afterCompletionCallback] - ResourceLocalTransactionCoordinatorImpl#afterCompletionCallback(true)
o.h.r.t.i.SynchronizationRegistryStandardImpl [tracef] - SynchronizationRegistryStandardImpl.notifySynchronizationsAfterTransactionCompletion(3)
org.hibernate.internal.SessionImpl [afterTransactionCompletion] - SessionImpl#afterTransactionCompletion(successful=true, delayed=false)

a.a.b.d.conversion.InspectionFeedbackController [findByInspector] - =====>> 서비스 호출 후
org.hibernate.internal.SessionImpl [immediateLoad] - Initializing proxy: [ai.alethio.babyface.domain.conversion.InspectionFeedback#1]
o.h.event.internal.DefaultLoadEventListener [doLoad] - Attempting to resolve: [ai.alethio.babyface.domain.conversion.InspectionFeedback#1]
o.h.event.internal.DefaultLoadEventListener [doLoad] - Object not resolved in any cache: [ai.alethio.babyface.domain.conversion.InspectionFeedback#1]
o.h.persister.entity.AbstractEntityPersister [load] - Fetching entity: [ai.alethio.babyface.domain.conversion.InspectionFeedback#1]
org.hibernate.SQL [logStatement] - select inspection0_.id as id1_16_0_, inspection0_.after_image as after_im2_16_0_, inspection0_.before_image as before_i3_16_0_, inspection0_.checked as checked4_16_0_, inspection0_.conversion_request_id as conversi9_16_0_, inspection0_.create_date_time as create_d5_16_0_, inspection0_.final_inspector_id as final_i10_16_0_, inspection0_.inspector_id as inspect11_16_0_, inspection0_.message as message6_16_0_, inspection0_.status as status7_16_0_, inspection0_.update_date_time as update_d8_16_0_ from inspection_feedback inspection0_ where inspection0_.id=?
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [register] - Registering statement [HikariProxyPreparedStatement@1670172908 wrapping com.mysql.jdbc.JDBC42PreparedStatement@48fc8a4f: select inspection0_.id as id1_16_0_, inspection0_.after_image as after_im2_16_0_, inspection0_.before_image as before_i3_16_0_, inspection0_.checked as checked4_16_0_, inspection0_.conversion_request_id as conversi9_16_0_, inspection0_.create_date_time as create_d5_16_0_, inspection0_.final_inspector_id as final_i10_16_0_, inspection0_.inspector_id as inspect11_16_0_, inspection0_.message as message6_16_0_, inspection0_.status as status7_16_0_, inspection0_.update_date_time as update_d8_16_0_ from inspection_feedback inspection0_ where inspection0_.id=** NOT SPECIFIED **]
o.h.engine.jdbc.internal.JdbcCoordinatorImpl [registerLastQuery] - Registering last query statement [HikariProxyPreparedStatement@1670172908 wrapping com.mysql.jdbc.JDBC42PreparedStatement@48fc8a4f: select inspection0_.id as id1_16_0_, inspection0_.after_image as after_im2_16_0_, inspection0_.before_image as before_i3_16_0_, inspection0_.checked as checked4_16_0_, inspection0_.conversion_request_id as conversi9_16_0_, inspection0_.create_date_time as create_d5_16_0_, inspection0_.final_inspector_id as final_i10_16_0_, inspection0_.inspector_id as inspect11_16_0_, inspection0_.message as message6_16_0_, inspection0_.status as status7_16_0_, inspection0_.update_date_time as update_d8_16_0_ from inspection_feedback inspection0_ where inspection0_.id=** NOT SPECIFIED **]
org.hibernate.type.descriptor.sql.BasicBinder [bind] - binding parameter [1] as [BIGINT] - [1]
o.h.l.p.exec.internal.AbstractLoadPlanBasedLoader [prepareQueryStatement] - Bound [2] parameters total
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [register] - Registering result set [HikariProxyResultSet@1677412649 wrapping com.mysql.jdbc.JDBC42ResultSet@4b3a3279]
o.h.l.p.e.process.internal.ResultSetProcessorImpl [extractResults] - Processing result set
o.h.l.p.e.process.internal.ResultSetProcessorImpl [extractResults] - Starting ResultSet row #0
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [resolveEntityKey] - On call to EntityIdentifierReaderImpl#resolve, EntityKey was already known; should only happen on root returns with an optional identifier specified
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [hydrateEntityState] - hydrating entity state
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [loadFromResultSet] - Initializing object from ResultSet: [ai.alethio.babyface.domain.conversion.InspectionFeedback#1]
o.h.persister.entity.AbstractEntityPersister [hydrate] - Hydrating entity: [ai.alethio.babyface.domain.conversion.InspectionFeedback#1]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([after_im2_16_0_] : [VARCHAR]) - [https://kr.object.ncloudstorage.com/alethio-storage/converted/2021/12-17/97fba34cca0a45b98dfb9fe4c3ee86fc.png]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([before_i3_16_0_] : [VARCHAR]) - [https://kr.object.ncloudstorage.com/alethio-storage/converted/2021/12-17/97fba34cca0a45b98dfb9fe4c3ee86fc.png]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([checked4_16_0_] : [BOOLEAN]) - [false]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([conversi9_16_0_] : [BIGINT]) - [72834]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([create_d5_16_0_] : [TIMESTAMP]) - [2021-12-23T16:57]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([final_i10_16_0_] : [BIGINT]) - [18]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([inspect11_16_0_] : [BIGINT]) - [65547]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([message6_16_0_] : [VARCHAR]) - [ㅇㄹㅇㄹㅇㄹㅇㄹ]
org.hibernate.type.EnumType [getValue] - Returning [COMPLETED] as column [status7_16_0_]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([update_d8_16_0_] : [TIMESTAMP]) - [2021-12-23T17:10:38]
o.h.l.p.e.process.internal.ResultSetProcessorImpl [extractResults] - Done processing result set (1 rows)
o.h.l.plan.exec.process.internal.AbstractRowReader [performTwoPhaseLoad] - Total objects hydrated: 1
org.hibernate.engine.internal.TwoPhaseLoad [doInitializeEntity] - Resolving associations for [ai.alethio.babyface.domain.conversion.InspectionFeedback#1]
o.h.event.internal.DefaultLoadEventListener [proxyOrLoad] - Loading entity: [ai.alethio.babyface.domain.conversion.ConversionRequest#72834]
o.h.event.internal.DefaultLoadEventListener [createProxyIfNecessary] - Creating new proxy for entity
o.h.event.internal.DefaultLoadEventListener [proxyOrLoad] - Loading entity: [ai.alethio.babyface.domain.final_inspector.domain.FinalInspector#18]
o.h.event.internal.DefaultLoadEventListener [createProxyIfNecessary] - Creating new proxy for entity
o.h.event.internal.DefaultLoadEventListener [proxyOrLoad] - Loading entity: [ai.alethio.babyface.domain.inspector.domain.Inspector#65547]
o.h.event.internal.DefaultLoadEventListener [createProxyIfNecessary] - Creating new proxy for entity
org.hibernate.engine.internal.TwoPhaseLoad [doInitializeEntity] - Done materializing entity [ai.alethio.babyface.domain.conversion.InspectionFeedback#1]
o.h.l.p.e.p.i.ResultSetProcessingContextImpl [createSubselects] - Skipping create subselects because there are fewer than 2 results, so query by key is more efficient.
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [release] - Releasing result set [HikariProxyResultSet@1677412649 wrapping com.mysql.jdbc.JDBC42ResultSet@4b3a3279]
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [close] - Closing result set [HikariProxyResultSet@1677412649 wrapping com.mysql.jdbc.JDBC42ResultSet@4b3a3279]
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [release] - Releasing statement [HikariProxyPreparedStatement@1670172908 wrapping com.mysql.jdbc.JDBC42PreparedStatement@48fc8a4f: select inspection0_.id as id1_16_0_, inspection0_.after_image as after_im2_16_0_, inspection0_.before_image as before_i3_16_0_, inspection0_.checked as checked4_16_0_, inspection0_.conversion_request_id as conversi9_16_0_, inspection0_.create_date_time as create_d5_16_0_, inspection0_.final_inspector_id as final_i10_16_0_, inspection0_.inspector_id as inspect11_16_0_, inspection0_.message as message6_16_0_, inspection0_.status as status7_16_0_, inspection0_.update_date_time as update_d8_16_0_ from inspection_feedback inspection0_ where inspection0_.id=1]
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [release] - HHH000387: ResultSet's statement was not registered
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [close] - Closing prepared statement [HikariProxyPreparedStatement@1670172908 wrapping com.mysql.jdbc.JDBC42PreparedStatement@48fc8a4f: select inspection0_.id as id1_16_0_, inspection0_.after_image as after_im2_16_0_, inspection0_.before_image as before_i3_16_0_, inspection0_.checked as checked4_16_0_, inspection0_.conversion_request_id as conversi9_16_0_, inspection0_.create_date_time as create_d5_16_0_, inspection0_.final_inspector_id as final_i10_16_0_, inspection0_.inspector_id as inspect11_16_0_, inspection0_.message as message6_16_0_, inspection0_.status as status7_16_0_, inspection0_.update_date_time as update_d8_16_0_ from inspection_feedback inspection0_ where inspection0_.id=1]
o.h.engine.jdbc.internal.JdbcCoordinatorImpl [afterStatementExecution] - Starting after statement execution processing [ON_CLOSE]
o.h.engine.internal.StatefulPersistenceContext [initializeNonLazyCollections] - Initializing non-lazy collections
o.h.l.e.plan.AbstractLoadPlanBasedEntityLoader [load] - Done entity load : ai.alethio.babyface.domain.conversion.InspectionFeedback#1
org.hibernate.internal.SessionImpl [immediateLoad] - Initializing proxy: [ai.alethio.babyface.domain.conversion.ConversionRequest#72834]
o.h.event.internal.DefaultLoadEventListener [doLoad] - Attempting to resolve: [ai.alethio.babyface.domain.conversion.ConversionRequest#72834]
o.h.event.internal.DefaultLoadEventListener [doLoad] - Object not resolved in any cache: [ai.alethio.babyface.domain.conversion.ConversionRequest#72834]
o.h.persister.entity.AbstractEntityPersister [load] - Fetching entity: [ai.alethio.babyface.domain.conversion.ConversionRequest#72834]
org.hibernate.SQL [logStatement] - select conversion0_.id as id1_24_0_, conversion0_1_.default_price as default_2_24_0_, conversion0_1_.default_shipping_fee as default_3_24_0_, conversion0_1_.final_price as final_pr4_24_0_, conversion0_1_.final_shipping_fee as final_sh5_24_0_, conversion0_1_.original_price as original6_24_0_, conversion0_1_.affiliate_id as affiliat7_24_0_, conversion0_1_.address as address8_24_0_, conversion0_1_.contact_email as contact_9_24_0_, conversion0_1_.contact_name as contact10_24_0_, conversion0_1_.detail_address as detail_11_24_0_, conversion0_1_.mobile as mobile12_24_0_, conversion0_1_.phone as phone13_24_0_, conversion0_1_.zipcode as zipcode14_24_0_, conversion0_1_.buyer_id as buyer_i25_24_0_, conversion0_1_.create_date_time as create_15_24_0_, conversion0_1_.download_locked as downloa16_24_0_, conversion0_1_.fast_processing as fast_pr17_24_0_, conversion0_1_.internal_description as interna18_24_0_, conversion0_1_.item_id as item_id26_24_0_, conversion0_1_.item_name as item_na19_24_0_, conversion0_1_.order_info_id as order_i27_24_0_, conversion0_1_.payment_complete_time as payment20_24_0_, conversion0_1_.price as price21_24_0_, conversion0_1_.seller_id as seller_28_24_0_, conversion0_1_.shipment_id as shipmen29_24_0_, conversion0_1_.shipment_required as shipmen22_24_0_, conversion0_1_.shipping_to_affiliate as shippin23_24_0_, conversion0_1_.update_date_time as update_24_24_0_, conversion0_.baby_gender as baby_gen1_7_0_, conversion0_.hospital_name as hospital2_7_0_, conversion0_.image_frame_alias as image_fr3_7_0_, conversion0_.message as message4_7_0_, conversion0_.note as note5_7_0_, conversion0_.photo_frame as photo_fr6_7_0_, conversion0_.conversion_deadline as conversi7_7_0_, conversion0_.delivered as delivere8_7_0_, conversion0_.delivery_deadline as delivery9_7_0_, conversion0_.first_complete_time as first_c10_7_0_, conversion0_.from_third_party as from_th11_7_0_, conversion0_.inspector_id as inspect24_7_0_, conversion0_.inspector_message as inspect12_7_0_, conversion0_.inspector_note as inspect13_7_0_, conversion0_.packaging_issue as packagi14_7_0_, conversion0_.previous_status as previou15_7_0_, conversion0_.printed as printed16_7_0_, conversion0_.remaining_tasks as remaini17_7_0_, conversion0_.reserved_completion_time as reserve18_7_0_, conversion0_.sales_country as sales_c19_7_0_, conversion0_.status as status20_7_0_, conversion0_.stored_status as stored_21_7_0_, conversion0_.tags as tags22_7_0_, enduser1_.id as id2_1_1_, enduser1_.account_id as account_3_1_1_, enduser1_.address as address4_1_1_, enduser1_.contact_email as contact_5_1_1_, enduser1_.contact_name as contact_6_1_1_, enduser1_.detail_address as detail_a7_1_1_, enduser1_.mobile as mobile8_1_1_, enduser1_.phone as phone9_1_1_, enduser1_.zipcode as zipcode10_1_1_, enduser1_.create_date_time as create_11_1_1_, enduser1_.email as email12_1_1_, enduser1_.name as name13_1_1_, enduser1_.update_date_time as update_14_1_1_, enduser1_.agree_terms_of_use as agree_t17_1_1_, enduser1_.allow_marketing as allow_m18_1_1_, enduser1_.allow_notification as allow_n19_1_1_, enduser1_.allow_personal_info as allow_p20_1_1_, enduser1_.tester as tester21_1_1_, enduser1_.wechat_open_id as wechat_22_1_1_, shipment2_.id as id1_34_2_, shipment2_.affiliate_id as affiliat2_34_2_, shipment2_.arrival_time as arrival_3_34_2_, shipment2_.bundled as bundled4_34_2_, shipment2_.confirm_time as confirm_5_34_2_, shipment2_.courier as courier6_34_2_, shipment2_.invoice_id as invoice_7_34_2_, shipment2_.item_name as item_nam8_34_2_, shipment2_.address as address9_34_2_, shipment2_.contact_email as contact10_34_2_, shipment2_.contact_name as contact11_34_2_, shipment2_.detail_address as detail_12_34_2_, shipment2_.mobile as mobile13_34_2_, shipment2_.phone as phone14_34_2_, shipment2_.zipcode as zipcode15_34_2_, shipment2_.send_time as send_ti16_34_2_, shipment2_.status as status17_34_2_, shipment2_.type as type18_34_2_, inspector3_.id as id2_1_3_, inspector3_.account_id as account_3_1_3_, inspector3_.address as address4_1_3_, inspector3_.contact_email as contact_5_1_3_, inspector3_.contact_name as contact_6_1_3_, inspector3_.detail_address as detail_a7_1_3_, inspector3_.mobile as mobile8_1_3_, inspector3_.phone as phone9_1_3_, inspector3_.zipcode as zipcode10_1_3_, inspector3_.create_date_time as create_11_1_3_, inspector3_.email as email12_1_3_, inspector3_.name as name13_1_3_, inspector3_.update_date_time as update_14_1_3_, inspector3_.dormant as dormant15_1_3_, inspector3_.slack_member_id as slack_m16_1_3_, inspector3_.dtype as dtype1_1_3_ from conversion_request conversion0_ inner join purchased_item conversion0_1_ on conversion0_.id=conversion0_1_.id left outer join abstract_user_profile enduser1_ on conversion0_1_.buyer_id=enduser1_.id left outer join shipment shipment2_ on conversion0_1_.shipment_id=shipment2_.id left outer join abstract_user_profile inspector3_ on conversion0_.inspector_id=inspector3_.id where conversion0_.id=?
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [register] - Registering statement [HikariProxyPreparedStatement@1577027503 wrapping com.mysql.jdbc.JDBC42PreparedStatement@7a80a31b: select conversion0_.id as id1_24_0_, conversion0_1_.default_price as default_2_24_0_, conversion0_1_.default_shipping_fee as default_3_24_0_, conversion0_1_.final_price as final_pr4_24_0_, conversion0_1_.final_shipping_fee as final_sh5_24_0_, conversion0_1_.original_price as original6_24_0_, conversion0_1_.affiliate_id as affiliat7_24_0_, conversion0_1_.address as address8_24_0_, conversion0_1_.contact_email as contact_9_24_0_, conversion0_1_.contact_name as contact10_24_0_, conversion0_1_.detail_address as detail_11_24_0_, conversion0_1_.mobile as mobile12_24_0_, conversion0_1_.phone as phone13_24_0_, conversion0_1_.zipcode as zipcode14_24_0_, conversion0_1_.buyer_id as buyer_i25_24_0_, conversion0_1_.create_date_time as create_15_24_0_, conversion0_1_.download_locked as downloa16_24_0_, conversion0_1_.fast_processing as fast_pr17_24_0_, conversion0_1_.internal_description as interna18_24_0_, conversion0_1_.item_id as item_id26_24_0_, conversion0_1_.item_name as item_na19_24_0_, conversion0_1_.order_info_id as order_i27_24_0_, conversion0_1_.payment_complete_time as payment20_24_0_, conversion0_1_.price as price21_24_0_, conversion0_1_.seller_id as seller_28_24_0_, conversion0_1_.shipment_id as shipmen29_24_0_, conversion0_1_.shipment_required as shipmen22_24_0_, conversion0_1_.shipping_to_affiliate as shippin23_24_0_, conversion0_1_.update_date_time as update_24_24_0_, conversion0_.baby_gender as baby_gen1_7_0_, conversion0_.hospital_name as hospital2_7_0_, conversion0_.image_frame_alias as image_fr3_7_0_, conversion0_.message as message4_7_0_, conversion0_.note as note5_7_0_, conversion0_.photo_frame as photo_fr6_7_0_, conversion0_.conversion_deadline as conversi7_7_0_, conversion0_.delivered as delivere8_7_0_, conversion0_.delivery_deadline as delivery9_7_0_, conversion0_.first_complete_time as first_c10_7_0_, conversion0_.from_third_party as from_th11_7_0_, conversion0_.inspector_id as inspect24_7_0_, conversion0_.inspector_message as inspect12_7_0_, conversion0_.inspector_note as inspect13_7_0_, conversion0_.packaging_issue as packagi14_7_0_, conversion0_.previous_status as previou15_7_0_, conversion0_.printed as printed16_7_0_, conversion0_.remaining_tasks as remaini17_7_0_, conversion0_.reserved_completion_time as reserve18_7_0_, conversion0_.sales_country as sales_c19_7_0_, conversion0_.status as status20_7_0_, conversion0_.stored_status as stored_21_7_0_, conversion0_.tags as tags22_7_0_, enduser1_.id as id2_1_1_, enduser1_.account_id as account_3_1_1_, enduser1_.address as address4_1_1_, enduser1_.contact_email as contact_5_1_1_, enduser1_.contact_name as contact_6_1_1_, enduser1_.detail_address as detail_a7_1_1_, enduser1_.mobile as mobile8_1_1_, enduser1_.phone as phone9_1_1_, enduser1_.zipcode as zipcode10_1_1_, enduser1_.create_date_time as create_11_1_1_, enduser1_.email as email12_1_1_, enduser1_.name as name13_1_1_, enduser1_.update_date_time as update_14_1_1_, enduser1_.agree_terms_of_use as agree_t17_1_1_, enduser1_.allow_marketing as allow_m18_1_1_, enduser1_.allow_notification as allow_n19_1_1_, enduser1_.allow_personal_info as allow_p20_1_1_, enduser1_.tester as tester21_1_1_, enduser1_.wechat_open_id as wechat_22_1_1_, shipment2_.id as id1_34_2_, shipment2_.affiliate_id as affiliat2_34_2_, shipment2_.arrival_time as arrival_3_34_2_, shipment2_.bundled as bundled4_34_2_, shipment2_.confirm_time as confirm_5_34_2_, shipment2_.courier as courier6_34_2_, shipment2_.invoice_id as invoice_7_34_2_, shipment2_.item_name as item_nam8_34_2_, shipment2_.address as address9_34_2_, shipment2_.contact_email as contact10_34_2_, shipment2_.contact_name as contact11_34_2_, shipment2_.detail_address as detail_12_34_2_, shipment2_.mobile as mobile13_34_2_, shipment2_.phone as phone14_34_2_, shipment2_.zipcode as zipcode15_34_2_, shipment2_.send_time as send_ti16_34_2_, shipment2_.status as status17_34_2_, shipment2_.type as type18_34_2_, inspector3_.id as id2_1_3_, inspector3_.account_id as account_3_1_3_, inspector3_.address as address4_1_3_, inspector3_.contact_email as contact_5_1_3_, inspector3_.contact_name as contact_6_1_3_, inspector3_.detail_address as detail_a7_1_3_, inspector3_.mobile as mobile8_1_3_, inspector3_.phone as phone9_1_3_, inspector3_.zipcode as zipcode10_1_3_, inspector3_.create_date_time as create_11_1_3_, inspector3_.email as email12_1_3_, inspector3_.name as name13_1_3_, inspector3_.update_date_time as update_14_1_3_, inspector3_.dormant as dormant15_1_3_, inspector3_.slack_member_id as slack_m16_1_3_, inspector3_.dtype as dtype1_1_3_ from conversion_request conversion0_ inner join purchased_item conversion0_1_ on conversion0_.id=conversion0_1_.id left outer join abstract_user_profile enduser1_ on conversion0_1_.buyer_id=enduser1_.id left outer join shipment shipment2_ on conversion0_1_.shipment_id=shipment2_.id left outer join abstract_user_profile inspector3_ on conversion0_.inspector_id=inspector3_.id where conversion0_.id=** NOT SPECIFIED **]
o.h.engine.jdbc.internal.JdbcCoordinatorImpl [registerLastQuery] - Registering last query statement [HikariProxyPreparedStatement@1577027503 wrapping com.mysql.jdbc.JDBC42PreparedStatement@7a80a31b: select conversion0_.id as id1_24_0_, conversion0_1_.default_price as default_2_24_0_, conversion0_1_.default_shipping_fee as default_3_24_0_, conversion0_1_.final_price as final_pr4_24_0_, conversion0_1_.final_shipping_fee as final_sh5_24_0_, conversion0_1_.original_price as original6_24_0_, conversion0_1_.affiliate_id as affiliat7_24_0_, conversion0_1_.address as address8_24_0_, conversion0_1_.contact_email as contact_9_24_0_, conversion0_1_.contact_name as contact10_24_0_, conversion0_1_.detail_address as detail_11_24_0_, conversion0_1_.mobile as mobile12_24_0_, conversion0_1_.phone as phone13_24_0_, conversion0_1_.zipcode as zipcode14_24_0_, conversion0_1_.buyer_id as buyer_i25_24_0_, conversion0_1_.create_date_time as create_15_24_0_, conversion0_1_.download_locked as downloa16_24_0_, conversion0_1_.fast_processing as fast_pr17_24_0_, conversion0_1_.internal_description as interna18_24_0_, conversion0_1_.item_id as item_id26_24_0_, conversion0_1_.item_name as item_na19_24_0_, conversion0_1_.order_info_id as order_i27_24_0_, conversion0_1_.payment_complete_time as payment20_24_0_, conversion0_1_.price as price21_24_0_, conversion0_1_.seller_id as seller_28_24_0_, conversion0_1_.shipment_id as shipmen29_24_0_, conversion0_1_.shipment_required as shipmen22_24_0_, conversion0_1_.shipping_to_affiliate as shippin23_24_0_, conversion0_1_.update_date_time as update_24_24_0_, conversion0_.baby_gender as baby_gen1_7_0_, conversion0_.hospital_name as hospital2_7_0_, conversion0_.image_frame_alias as image_fr3_7_0_, conversion0_.message as message4_7_0_, conversion0_.note as note5_7_0_, conversion0_.photo_frame as photo_fr6_7_0_, conversion0_.conversion_deadline as conversi7_7_0_, conversion0_.delivered as delivere8_7_0_, conversion0_.delivery_deadline as delivery9_7_0_, conversion0_.first_complete_time as first_c10_7_0_, conversion0_.from_third_party as from_th11_7_0_, conversion0_.inspector_id as inspect24_7_0_, conversion0_.inspector_message as inspect12_7_0_, conversion0_.inspector_note as inspect13_7_0_, conversion0_.packaging_issue as packagi14_7_0_, conversion0_.previous_status as previou15_7_0_, conversion0_.printed as printed16_7_0_, conversion0_.remaining_tasks as remaini17_7_0_, conversion0_.reserved_completion_time as reserve18_7_0_, conversion0_.sales_country as sales_c19_7_0_, conversion0_.status as status20_7_0_, conversion0_.stored_status as stored_21_7_0_, conversion0_.tags as tags22_7_0_, enduser1_.id as id2_1_1_, enduser1_.account_id as account_3_1_1_, enduser1_.address as address4_1_1_, enduser1_.contact_email as contact_5_1_1_, enduser1_.contact_name as contact_6_1_1_, enduser1_.detail_address as detail_a7_1_1_, enduser1_.mobile as mobile8_1_1_, enduser1_.phone as phone9_1_1_, enduser1_.zipcode as zipcode10_1_1_, enduser1_.create_date_time as create_11_1_1_, enduser1_.email as email12_1_1_, enduser1_.name as name13_1_1_, enduser1_.update_date_time as update_14_1_1_, enduser1_.agree_terms_of_use as agree_t17_1_1_, enduser1_.allow_marketing as allow_m18_1_1_, enduser1_.allow_notification as allow_n19_1_1_, enduser1_.allow_personal_info as allow_p20_1_1_, enduser1_.tester as tester21_1_1_, enduser1_.wechat_open_id as wechat_22_1_1_, shipment2_.id as id1_34_2_, shipment2_.affiliate_id as affiliat2_34_2_, shipment2_.arrival_time as arrival_3_34_2_, shipment2_.bundled as bundled4_34_2_, shipment2_.confirm_time as confirm_5_34_2_, shipment2_.courier as courier6_34_2_, shipment2_.invoice_id as invoice_7_34_2_, shipment2_.item_name as item_nam8_34_2_, shipment2_.address as address9_34_2_, shipment2_.contact_email as contact10_34_2_, shipment2_.contact_name as contact11_34_2_, shipment2_.detail_address as detail_12_34_2_, shipment2_.mobile as mobile13_34_2_, shipment2_.phone as phone14_34_2_, shipment2_.zipcode as zipcode15_34_2_, shipment2_.send_time as send_ti16_34_2_, shipment2_.status as status17_34_2_, shipment2_.type as type18_34_2_, inspector3_.id as id2_1_3_, inspector3_.account_id as account_3_1_3_, inspector3_.address as address4_1_3_, inspector3_.contact_email as contact_5_1_3_, inspector3_.contact_name as contact_6_1_3_, inspector3_.detail_address as detail_a7_1_3_, inspector3_.mobile as mobile8_1_3_, inspector3_.phone as phone9_1_3_, inspector3_.zipcode as zipcode10_1_3_, inspector3_.create_date_time as create_11_1_3_, inspector3_.email as email12_1_3_, inspector3_.name as name13_1_3_, inspector3_.update_date_time as update_14_1_3_, inspector3_.dormant as dormant15_1_3_, inspector3_.slack_member_id as slack_m16_1_3_, inspector3_.dtype as dtype1_1_3_ from conversion_request conversion0_ inner join purchased_item conversion0_1_ on conversion0_.id=conversion0_1_.id left outer join abstract_user_profile enduser1_ on conversion0_1_.buyer_id=enduser1_.id left outer join shipment shipment2_ on conversion0_1_.shipment_id=shipment2_.id left outer join abstract_user_profile inspector3_ on conversion0_.inspector_id=inspector3_.id where conversion0_.id=** NOT SPECIFIED **]
org.hibernate.type.descriptor.sql.BasicBinder [bind] - binding parameter [1] as [BIGINT] - [72834]
o.h.l.p.exec.internal.AbstractLoadPlanBasedLoader [prepareQueryStatement] - Bound [2] parameters total
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [register] - Registering result set [HikariProxyResultSet@1215965951 wrapping com.mysql.jdbc.JDBC42ResultSet@69990ea0]
o.h.l.p.e.process.internal.ResultSetProcessorImpl [extractResults] - Processing result set
o.h.l.p.e.process.internal.ResultSetProcessorImpl [extractResults] - Starting ResultSet row #0
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([id2_1_1_] : [BIGINT]) - [62733]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([id1_34_2_] : [BIGINT]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([id2_1_3_] : [BIGINT]) - [72977]
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [resolveEntityKey] - On call to EntityIdentifierReaderImpl#resolve, EntityKey was already known; should only happen on root returns with an optional identifier specified
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [hydrateEntityState] - hydrating entity state
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [loadFromResultSet] - Initializing object from ResultSet: [ai.alethio.babyface.domain.conversion.ConversionRequest#72834]
o.h.persister.entity.AbstractEntityPersister [hydrate] - Hydrating entity: [ai.alethio.babyface.domain.conversion.ConversionRequest#72834]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([default_2_24_0_] : [BIGINT]) - [33000]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([default_3_24_0_] : [BIGINT]) - [2500]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([final_pr4_24_0_] : [BIGINT]) - [33000]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([final_sh5_24_0_] : [BIGINT]) - [2500]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([original6_24_0_] : [BIGINT]) - [33000]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([affiliat7_24_0_] : [BIGINT]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([address8_24_0_] : [VARCHAR]) - [서울 강남구 도산대로 240]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([contact_9_24_0_] : [VARCHAR]) - [0701@alethio.io]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([contact10_24_0_] : [VARCHAR]) - [sksk]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([detail_11_24_0_] : [VARCHAR]) - [테스트완료ㅇㅇ]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([mobile12_24_0_] : [VARCHAR]) - [01092914886]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([phone13_24_0_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([zipcode14_24_0_] : [VARCHAR]) - [06048]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([buyer_i25_24_0_] : [BIGINT]) - [62733]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([create_15_24_0_] : [TIMESTAMP]) - [2021-12-17T09:02:56]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([downloa16_24_0_] : [BOOLEAN]) - [false]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([fast_pr17_24_0_] : [BOOLEAN]) - [false]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([interna18_24_0_] : [VARCHAR]) - [분석 3일 소요;(70x82mm)아기 얼굴 예측 사진 ⨯ 3장;(127x89mm)베이비페이스 ⨯ 3장]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([item_id26_24_0_] : [BIGINT]) - [0]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([item_na19_24_0_] : [VARCHAR]) - [인공지능 초음파 분석 3일 분석+사진 인화]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([order_i27_24_0_] : [BIGINT]) - [72836]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([payment20_24_0_] : [TIMESTAMP]) - [2021-12-17T09:02:55]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([price21_24_0_] : [BIGINT]) - [33000]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([seller_28_24_0_] : [BIGINT]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([shipmen29_24_0_] : [BIGINT]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([shipmen22_24_0_] : [BOOLEAN]) - [true]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([shippin23_24_0_] : [BOOLEAN]) - [false]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([update_24_24_0_] : [TIMESTAMP]) - [2021-12-24T18:34:52]
org.hibernate.type.EnumType [getValue] - Returning null as column [baby_gen1_7_0_]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([hospital2_7_0_] : [VARCHAR]) - []
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([image_fr3_7_0_] : [VARCHAR]) - [2020_반갑소]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([message4_7_0_] : [VARCHAR]) - []
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([note5_7_0_] : [VARCHAR]) - []
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([photo_fr6_7_0_] : [BOOLEAN]) - [false]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([conversi7_7_0_] : [TIMESTAMP]) - [2021-12-22T00:02:55]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([delivere8_7_0_] : [BOOLEAN]) - [false]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([delivery9_7_0_] : [TIMESTAMP]) - [2021-12-23T08:00]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([first_c10_7_0_] : [TIMESTAMP]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([from_th11_7_0_] : [BOOLEAN]) - [false]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([inspect24_7_0_] : [BIGINT]) - [72977]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([inspect12_7_0_] : [VARCHAR]) - [베이비페이스 인공지능은 입체초음파의 '눈, 코, 입'을 중심으로 분석을 합니다.
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([inspect13_7_0_] : [VARCHAR]) - [ㅇㄹㅇㄹㅇㄹㅇㄹ]
org.hibernate.type.EnumType [getValue] - Returning [NONE] as column [packagi14_7_0_]
org.hibernate.type.EnumType [getValue] - Returning [CS_REVIEW] as column [previou15_7_0_]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([printed16_7_0_] : [BOOLEAN]) - [false]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([remaini17_7_0_] : [BIGINT]) - [1]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([reserve18_7_0_] : [TIMESTAMP]) - [2021-12-17T14:00]
org.hibernate.type.EnumType [getValue] - Returning [KOREA] as column [sales_c19_7_0_]
org.hibernate.type.EnumType [getValue] - Returning [CS_REWORK] as column [status20_7_0_]
org.hibernate.type.EnumType [getValue] - Returning [COMPLETED] as column [stored_21_7_0_]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([tags22_7_0_] : [VARCHAR]) - [null]
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [hydrateEntityState] - hydrating entity state
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [loadFromResultSet] - Initializing object from ResultSet: [ai.alethio.babyface.domain.user.Enduser#62733]
o.h.persister.entity.AbstractEntityPersister [hydrate] - Hydrating entity: [ai.alethio.babyface.domain.user.Enduser#62733]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([account_3_1_1_] : [BIGINT]) - [771]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([address4_1_1_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([contact_5_1_1_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([contact_6_1_1_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([detail_a7_1_1_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([mobile8_1_1_] : [VARCHAR]) - [01092914886]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([phone9_1_1_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([zipcode10_1_1_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([create_11_1_1_] : [TIMESTAMP]) - [2020-06-30T17:35:20]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([email12_1_1_] : [VARCHAR]) - [0701@alethio.io]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([name13_1_1_] : [VARCHAR]) - [진선경]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([update_14_1_1_] : [TIMESTAMP]) - [2020-06-30T17:35:20]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([agree_t17_1_1_] : [BOOLEAN]) - [true]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([allow_m18_1_1_] : [BOOLEAN]) - [true]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([allow_n19_1_1_] : [BOOLEAN]) - [true]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([allow_p20_1_1_] : [BOOLEAN]) - [true]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([tester21_1_1_] : [BOOLEAN]) - [true]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([wechat_22_1_1_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([dtype1_1_3_] : [VARCHAR]) - [Inspector]
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [hydrateEntityState] - hydrating entity state
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [loadFromResultSet] - Initializing object from ResultSet: [ai.alethio.babyface.domain.inspector.domain.Inspector#72977]
o.h.persister.entity.AbstractEntityPersister [hydrate] - Hydrating entity: [ai.alethio.babyface.domain.inspector.domain.Inspector#72977]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([account_3_1_3_] : [BIGINT]) - [1403]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([address4_1_3_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([contact_5_1_3_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([contact_6_1_3_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([detail_a7_1_3_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([mobile8_1_3_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([phone9_1_3_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([zipcode10_1_3_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([create_11_1_3_] : [TIMESTAMP]) - [2021-12-23T16:02:05]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([email12_1_3_] : [VARCHAR]) - [test-a@alethio.io]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([name13_1_3_] : [VARCHAR]) - [일반-a]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([update_14_1_3_] : [TIMESTAMP]) - [2021-12-23T16:02:05]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([dormant15_1_3_] : [BOOLEAN]) - [false]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([slack_m16_1_3_] : [VARCHAR]) - [null]
o.h.l.p.e.process.internal.ResultSetProcessorImpl [extractResults] - Done processing result set (1 rows)
o.h.l.plan.exec.process.internal.AbstractRowReader [performTwoPhaseLoad] - Total objects hydrated: 3
org.hibernate.engine.internal.TwoPhaseLoad [doInitializeEntity] - Resolving associations for [ai.alethio.babyface.domain.conversion.ConversionRequest#72834]
o.h.event.internal.DefaultLoadEventListener [proxyOrLoad] - Loading entity: [ai.alethio.babyface.domain.user.Enduser#62733]
o.h.event.internal.DefaultLoadEventListener [doLoad] - Attempting to resolve: [ai.alethio.babyface.domain.user.Enduser#62733]
o.h.event.internal.DefaultLoadEventListener [doLoad] - Resolved object in session cache: [ai.alethio.babyface.domain.user.Enduser#62733]
o.h.event.internal.DefaultLoadEventListener [proxyOrLoad] - Loading entity: [ai.alethio.babyface.domain.item.AbstractSalesItem#0]
o.h.event.internal.DefaultLoadEventListener [createProxyIfNecessary] - Creating new proxy for entity
org.hibernate.type.CollectionType [getCollection] - Created collection wrapper: [ai.alethio.babyface.domain.order.PurchasedItem.options#72834]
o.h.event.internal.DefaultLoadEventListener [proxyOrLoad] - Loading entity: [ai.alethio.babyface.domain.order.OrderInfo#72836]
o.h.event.internal.DefaultLoadEventListener [createProxyIfNecessary] - Creating new proxy for entity
o.h.event.internal.DefaultLoadEventListener [proxyOrLoad] - Loading entity: [ai.alethio.babyface.domain.inspector.domain.Inspector#72977]
o.h.event.internal.DefaultLoadEventListener [doLoad] - Attempting to resolve: [ai.alethio.babyface.domain.inspector.domain.Inspector#72977]
o.h.event.internal.DefaultLoadEventListener [doLoad] - Resolved object in session cache: [ai.alethio.babyface.domain.inspector.domain.Inspector#72977]
org.hibernate.engine.internal.TwoPhaseLoad [doInitializeEntity] - Done materializing entity [ai.alethio.babyface.domain.conversion.ConversionRequest#72834]
org.hibernate.engine.internal.TwoPhaseLoad [doInitializeEntity] - Resolving associations for [ai.alethio.babyface.domain.user.Enduser#62733]
org.hibernate.engine.internal.TwoPhaseLoad [doInitializeEntity] - Done materializing entity [ai.alethio.babyface.domain.user.Enduser#62733]
org.hibernate.engine.internal.TwoPhaseLoad [doInitializeEntity] - Resolving associations for [ai.alethio.babyface.domain.inspector.domain.Inspector#72977]
org.hibernate.engine.internal.TwoPhaseLoad [doInitializeEntity] - Done materializing entity [ai.alethio.babyface.domain.inspector.domain.Inspector#72977]
o.h.l.p.e.p.i.ResultSetProcessingContextImpl [createSubselects] - Skipping create subselects because there are fewer than 2 results, so query by key is more efficient.
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [release] - Releasing result set [HikariProxyResultSet@1215965951 wrapping com.mysql.jdbc.JDBC42ResultSet@69990ea0]
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [close] - Closing result set [HikariProxyResultSet@1215965951 wrapping com.mysql.jdbc.JDBC42ResultSet@69990ea0]
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [release] - Releasing statement [HikariProxyPreparedStatement@1577027503 wrapping com.mysql.jdbc.JDBC42PreparedStatement@7a80a31b: select conversion0_.id as id1_24_0_, conversion0_1_.default_price as default_2_24_0_, conversion0_1_.default_shipping_fee as default_3_24_0_, conversion0_1_.final_price as final_pr4_24_0_, conversion0_1_.final_shipping_fee as final_sh5_24_0_, conversion0_1_.original_price as original6_24_0_, conversion0_1_.affiliate_id as affiliat7_24_0_, conversion0_1_.address as address8_24_0_, conversion0_1_.contact_email as contact_9_24_0_, conversion0_1_.contact_name as contact10_24_0_, conversion0_1_.detail_address as detail_11_24_0_, conversion0_1_.mobile as mobile12_24_0_, conversion0_1_.phone as phone13_24_0_, conversion0_1_.zipcode as zipcode14_24_0_, conversion0_1_.buyer_id as buyer_i25_24_0_, conversion0_1_.create_date_time as create_15_24_0_, conversion0_1_.download_locked as downloa16_24_0_, conversion0_1_.fast_processing as fast_pr17_24_0_, conversion0_1_.internal_description as interna18_24_0_, conversion0_1_.item_id as item_id26_24_0_, conversion0_1_.item_name as item_na19_24_0_, conversion0_1_.order_info_id as order_i27_24_0_, conversion0_1_.payment_complete_time as payment20_24_0_, conversion0_1_.price as price21_24_0_, conversion0_1_.seller_id as seller_28_24_0_, conversion0_1_.shipment_id as shipmen29_24_0_, conversion0_1_.shipment_required as shipmen22_24_0_, conversion0_1_.shipping_to_affiliate as shippin23_24_0_, conversion0_1_.update_date_time as update_24_24_0_, conversion0_.baby_gender as baby_gen1_7_0_, conversion0_.hospital_name as hospital2_7_0_, conversion0_.image_frame_alias as image_fr3_7_0_, conversion0_.message as message4_7_0_, conversion0_.note as note5_7_0_, conversion0_.photo_frame as photo_fr6_7_0_, conversion0_.conversion_deadline as conversi7_7_0_, conversion0_.delivered as delivere8_7_0_, conversion0_.delivery_deadline as delivery9_7_0_, conversion0_.first_complete_time as first_c10_7_0_, conversion0_.from_third_party as from_th11_7_0_, conversion0_.inspector_id as inspect24_7_0_, conversion0_.inspector_message as inspect12_7_0_, conversion0_.inspector_note as inspect13_7_0_, conversion0_.packaging_issue as packagi14_7_0_, conversion0_.previous_status as previou15_7_0_, conversion0_.printed as printed16_7_0_, conversion0_.remaining_tasks as remaini17_7_0_, conversion0_.reserved_completion_time as reserve18_7_0_, conversion0_.sales_country as sales_c19_7_0_, conversion0_.status as status20_7_0_, conversion0_.stored_status as stored_21_7_0_, conversion0_.tags as tags22_7_0_, enduser1_.id as id2_1_1_, enduser1_.account_id as account_3_1_1_, enduser1_.address as address4_1_1_, enduser1_.contact_email as contact_5_1_1_, enduser1_.contact_name as contact_6_1_1_, enduser1_.detail_address as detail_a7_1_1_, enduser1_.mobile as mobile8_1_1_, enduser1_.phone as phone9_1_1_, enduser1_.zipcode as zipcode10_1_1_, enduser1_.create_date_time as create_11_1_1_, enduser1_.email as email12_1_1_, enduser1_.name as name13_1_1_, enduser1_.update_date_time as update_14_1_1_, enduser1_.agree_terms_of_use as agree_t17_1_1_, enduser1_.allow_marketing as allow_m18_1_1_, enduser1_.allow_notification as allow_n19_1_1_, enduser1_.allow_personal_info as allow_p20_1_1_, enduser1_.tester as tester21_1_1_, enduser1_.wechat_open_id as wechat_22_1_1_, shipment2_.id as id1_34_2_, shipment2_.affiliate_id as affiliat2_34_2_, shipment2_.arrival_time as arrival_3_34_2_, shipment2_.bundled as bundled4_34_2_, shipment2_.confirm_time as confirm_5_34_2_, shipment2_.courier as courier6_34_2_, shipment2_.invoice_id as invoice_7_34_2_, shipment2_.item_name as item_nam8_34_2_, shipment2_.address as address9_34_2_, shipment2_.contact_email as contact10_34_2_, shipment2_.contact_name as contact11_34_2_, shipment2_.detail_address as detail_12_34_2_, shipment2_.mobile as mobile13_34_2_, shipment2_.phone as phone14_34_2_, shipment2_.zipcode as zipcode15_34_2_, shipment2_.send_time as send_ti16_34_2_, shipment2_.status as status17_34_2_, shipment2_.type as type18_34_2_, inspector3_.id as id2_1_3_, inspector3_.account_id as account_3_1_3_, inspector3_.address as address4_1_3_, inspector3_.contact_email as contact_5_1_3_, inspector3_.contact_name as contact_6_1_3_, inspector3_.detail_address as detail_a7_1_3_, inspector3_.mobile as mobile8_1_3_, inspector3_.phone as phone9_1_3_, inspector3_.zipcode as zipcode10_1_3_, inspector3_.create_date_time as create_11_1_3_, inspector3_.email as email12_1_3_, inspector3_.name as name13_1_3_, inspector3_.update_date_time as update_14_1_3_, inspector3_.dormant as dormant15_1_3_, inspector3_.slack_member_id as slack_m16_1_3_, inspector3_.dtype as dtype1_1_3_ from conversion_request conversion0_ inner join purchased_item conversion0_1_ on conversion0_.id=conversion0_1_.id left outer join abstract_user_profile enduser1_ on conversion0_1_.buyer_id=enduser1_.id left outer join shipment shipment2_ on conversion0_1_.shipment_id=shipment2_.id left outer join abstract_user_profile inspector3_ on conversion0_.inspector_id=inspector3_.id where conversion0_.id=72834]
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [release] - HHH000387: ResultSet's statement was not registered
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [close] - Closing prepared statement [HikariProxyPreparedStatement@1577027503 wrapping com.mysql.jdbc.JDBC42PreparedStatement@7a80a31b: select conversion0_.id as id1_24_0_, conversion0_1_.default_price as default_2_24_0_, conversion0_1_.default_shipping_fee as default_3_24_0_, conversion0_1_.final_price as final_pr4_24_0_, conversion0_1_.final_shipping_fee as final_sh5_24_0_, conversion0_1_.original_price as original6_24_0_, conversion0_1_.affiliate_id as affiliat7_24_0_, conversion0_1_.address as address8_24_0_, conversion0_1_.contact_email as contact_9_24_0_, conversion0_1_.contact_name as contact10_24_0_, conversion0_1_.detail_address as detail_11_24_0_, conversion0_1_.mobile as mobile12_24_0_, conversion0_1_.phone as phone13_24_0_, conversion0_1_.zipcode as zipcode14_24_0_, conversion0_1_.buyer_id as buyer_i25_24_0_, conversion0_1_.create_date_time as create_15_24_0_, conversion0_1_.download_locked as downloa16_24_0_, conversion0_1_.fast_processing as fast_pr17_24_0_, conversion0_1_.internal_description as interna18_24_0_, conversion0_1_.item_id as item_id26_24_0_, conversion0_1_.item_name as item_na19_24_0_, conversion0_1_.order_info_id as order_i27_24_0_, conversion0_1_.payment_complete_time as payment20_24_0_, conversion0_1_.price as price21_24_0_, conversion0_1_.seller_id as seller_28_24_0_, conversion0_1_.shipment_id as shipmen29_24_0_, conversion0_1_.shipment_required as shipmen22_24_0_, conversion0_1_.shipping_to_affiliate as shippin23_24_0_, conversion0_1_.update_date_time as update_24_24_0_, conversion0_.baby_gender as baby_gen1_7_0_, conversion0_.hospital_name as hospital2_7_0_, conversion0_.image_frame_alias as image_fr3_7_0_, conversion0_.message as message4_7_0_, conversion0_.note as note5_7_0_, conversion0_.photo_frame as photo_fr6_7_0_, conversion0_.conversion_deadline as conversi7_7_0_, conversion0_.delivered as delivere8_7_0_, conversion0_.delivery_deadline as delivery9_7_0_, conversion0_.first_complete_time as first_c10_7_0_, conversion0_.from_third_party as from_th11_7_0_, conversion0_.inspector_id as inspect24_7_0_, conversion0_.inspector_message as inspect12_7_0_, conversion0_.inspector_note as inspect13_7_0_, conversion0_.packaging_issue as packagi14_7_0_, conversion0_.previous_status as previou15_7_0_, conversion0_.printed as printed16_7_0_, conversion0_.remaining_tasks as remaini17_7_0_, conversion0_.reserved_completion_time as reserve18_7_0_, conversion0_.sales_country as sales_c19_7_0_, conversion0_.status as status20_7_0_, conversion0_.stored_status as stored_21_7_0_, conversion0_.tags as tags22_7_0_, enduser1_.id as id2_1_1_, enduser1_.account_id as account_3_1_1_, enduser1_.address as address4_1_1_, enduser1_.contact_email as contact_5_1_1_, enduser1_.contact_name as contact_6_1_1_, enduser1_.detail_address as detail_a7_1_1_, enduser1_.mobile as mobile8_1_1_, enduser1_.phone as phone9_1_1_, enduser1_.zipcode as zipcode10_1_1_, enduser1_.create_date_time as create_11_1_1_, enduser1_.email as email12_1_1_, enduser1_.name as name13_1_1_, enduser1_.update_date_time as update_14_1_1_, enduser1_.agree_terms_of_use as agree_t17_1_1_, enduser1_.allow_marketing as allow_m18_1_1_, enduser1_.allow_notification as allow_n19_1_1_, enduser1_.allow_personal_info as allow_p20_1_1_, enduser1_.tester as tester21_1_1_, enduser1_.wechat_open_id as wechat_22_1_1_, shipment2_.id as id1_34_2_, shipment2_.affiliate_id as affiliat2_34_2_, shipment2_.arrival_time as arrival_3_34_2_, shipment2_.bundled as bundled4_34_2_, shipment2_.confirm_time as confirm_5_34_2_, shipment2_.courier as courier6_34_2_, shipment2_.invoice_id as invoice_7_34_2_, shipment2_.item_name as item_nam8_34_2_, shipment2_.address as address9_34_2_, shipment2_.contact_email as contact10_34_2_, shipment2_.contact_name as contact11_34_2_, shipment2_.detail_address as detail_12_34_2_, shipment2_.mobile as mobile13_34_2_, shipment2_.phone as phone14_34_2_, shipment2_.zipcode as zipcode15_34_2_, shipment2_.send_time as send_ti16_34_2_, shipment2_.status as status17_34_2_, shipment2_.type as type18_34_2_, inspector3_.id as id2_1_3_, inspector3_.account_id as account_3_1_3_, inspector3_.address as address4_1_3_, inspector3_.contact_email as contact_5_1_3_, inspector3_.contact_name as contact_6_1_3_, inspector3_.detail_address as detail_a7_1_3_, inspector3_.mobile as mobile8_1_3_, inspector3_.phone as phone9_1_3_, inspector3_.zipcode as zipcode10_1_3_, inspector3_.create_date_time as create_11_1_3_, inspector3_.email as email12_1_3_, inspector3_.name as name13_1_3_, inspector3_.update_date_time as update_14_1_3_, inspector3_.dormant as dormant15_1_3_, inspector3_.slack_member_id as slack_m16_1_3_, inspector3_.dtype as dtype1_1_3_ from conversion_request conversion0_ inner join purchased_item conversion0_1_ on conversion0_.id=conversion0_1_.id left outer join abstract_user_profile enduser1_ on conversion0_1_.buyer_id=enduser1_.id left outer join shipment shipment2_ on conversion0_1_.shipment_id=shipment2_.id left outer join abstract_user_profile inspector3_ on conversion0_.inspector_id=inspector3_.id where conversion0_.id=72834]
o.h.engine.jdbc.internal.JdbcCoordinatorImpl [afterStatementExecution] - Starting after statement execution processing [ON_CLOSE]
o.h.engine.internal.StatefulPersistenceContext [initializeNonLazyCollections] - Initializing non-lazy collections
o.h.l.e.plan.AbstractLoadPlanBasedEntityLoader [load] - Done entity load : ai.alethio.babyface.domain.conversion.ConversionRequest#72834
org.hibernate.internal.SessionImpl [immediateLoad] - Initializing proxy: [ai.alethio.babyface.domain.final_inspector.domain.FinalInspector#18]
o.h.event.internal.DefaultLoadEventListener [doLoad] - Attempting to resolve: [ai.alethio.babyface.domain.final_inspector.domain.FinalInspector#18]
o.h.event.internal.DefaultLoadEventListener [doLoad] - Object not resolved in any cache: [ai.alethio.babyface.domain.final_inspector.domain.FinalInspector#18]
o.h.persister.entity.AbstractEntityPersister [load] - Fetching entity: [ai.alethio.babyface.domain.final_inspector.domain.FinalInspector#18]
org.hibernate.SQL [logStatement] - select finalinspe0_.id as id2_1_0_, finalinspe0_.account_id as account_3_1_0_, finalinspe0_.address as address4_1_0_, finalinspe0_.contact_email as contact_5_1_0_, finalinspe0_.contact_name as contact_6_1_0_, finalinspe0_.detail_address as detail_a7_1_0_, finalinspe0_.mobile as mobile8_1_0_, finalinspe0_.phone as phone9_1_0_, finalinspe0_.zipcode as zipcode10_1_0_, finalinspe0_.create_date_time as create_11_1_0_, finalinspe0_.email as email12_1_0_, finalinspe0_.name as name13_1_0_, finalinspe0_.update_date_time as update_14_1_0_, finalinspe0_.dormant as dormant15_1_0_, finalinspe0_.slack_member_id as slack_m16_1_0_ from abstract_user_profile finalinspe0_ where finalinspe0_.id=? and finalinspe0_.dtype='FinalInspector'
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [register] - Registering statement [HikariProxyPreparedStatement@331696273 wrapping com.mysql.jdbc.JDBC42PreparedStatement@7474b512: select finalinspe0_.id as id2_1_0_, finalinspe0_.account_id as account_3_1_0_, finalinspe0_.address as address4_1_0_, finalinspe0_.contact_email as contact_5_1_0_, finalinspe0_.contact_name as contact_6_1_0_, finalinspe0_.detail_address as detail_a7_1_0_, finalinspe0_.mobile as mobile8_1_0_, finalinspe0_.phone as phone9_1_0_, finalinspe0_.zipcode as zipcode10_1_0_, finalinspe0_.create_date_time as create_11_1_0_, finalinspe0_.email as email12_1_0_, finalinspe0_.name as name13_1_0_, finalinspe0_.update_date_time as update_14_1_0_, finalinspe0_.dormant as dormant15_1_0_, finalinspe0_.slack_member_id as slack_m16_1_0_ from abstract_user_profile finalinspe0_ where finalinspe0_.id=** NOT SPECIFIED ** and finalinspe0_.dtype='FinalInspector']
o.h.engine.jdbc.internal.JdbcCoordinatorImpl [registerLastQuery] - Registering last query statement [HikariProxyPreparedStatement@331696273 wrapping com.mysql.jdbc.JDBC42PreparedStatement@7474b512: select finalinspe0_.id as id2_1_0_, finalinspe0_.account_id as account_3_1_0_, finalinspe0_.address as address4_1_0_, finalinspe0_.contact_email as contact_5_1_0_, finalinspe0_.contact_name as contact_6_1_0_, finalinspe0_.detail_address as detail_a7_1_0_, finalinspe0_.mobile as mobile8_1_0_, finalinspe0_.phone as phone9_1_0_, finalinspe0_.zipcode as zipcode10_1_0_, finalinspe0_.create_date_time as create_11_1_0_, finalinspe0_.email as email12_1_0_, finalinspe0_.name as name13_1_0_, finalinspe0_.update_date_time as update_14_1_0_, finalinspe0_.dormant as dormant15_1_0_, finalinspe0_.slack_member_id as slack_m16_1_0_ from abstract_user_profile finalinspe0_ where finalinspe0_.id=** NOT SPECIFIED ** and finalinspe0_.dtype='FinalInspector']
org.hibernate.type.descriptor.sql.BasicBinder [bind] - binding parameter [1] as [BIGINT] - [18]
o.h.l.p.exec.internal.AbstractLoadPlanBasedLoader [prepareQueryStatement] - Bound [2] parameters total
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [register] - Registering result set [HikariProxyResultSet@1560720478 wrapping com.mysql.jdbc.JDBC42ResultSet@427be06f]
o.h.l.p.e.process.internal.ResultSetProcessorImpl [extractResults] - Processing result set
o.h.l.p.e.process.internal.ResultSetProcessorImpl [extractResults] - Starting ResultSet row #0
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [resolveEntityKey] - On call to EntityIdentifierReaderImpl#resolve, EntityKey was already known; should only happen on root returns with an optional identifier specified
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [hydrateEntityState] - hydrating entity state
o.h.l.p.e.p.i.EntityReferenceInitializerImpl [loadFromResultSet] - Initializing object from ResultSet: [ai.alethio.babyface.domain.final_inspector.domain.FinalInspector#18]
o.h.persister.entity.AbstractEntityPersister [hydrate] - Hydrating entity: [ai.alethio.babyface.domain.final_inspector.domain.FinalInspector#18]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([account_3_1_0_] : [BIGINT]) - [3]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([address4_1_0_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([contact_5_1_0_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([contact_6_1_0_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([detail_a7_1_0_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([mobile8_1_0_] : [VARCHAR]) - [00000000001]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([phone9_1_0_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([zipcode10_1_0_] : [VARCHAR]) - [null]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([create_11_1_0_] : [TIMESTAMP]) - [2019-01-30T17:03:12]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([email12_1_0_] : [VARCHAR]) - [final-inspector@alethio.io]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([name13_1_0_] : [VARCHAR]) - [???]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([update_14_1_0_] : [TIMESTAMP]) - [2019-01-30T17:03:12]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([dormant15_1_0_] : [BOOLEAN]) - [false]
org.hibernate.type.descriptor.sql.BasicExtractor [extract] - extracted value ([slack_m16_1_0_] : [VARCHAR]) - [null]
o.h.l.p.e.process.internal.ResultSetProcessorImpl [extractResults] - Done processing result set (1 rows)
o.h.l.plan.exec.process.internal.AbstractRowReader [performTwoPhaseLoad] - Total objects hydrated: 1
org.hibernate.engine.internal.TwoPhaseLoad [doInitializeEntity] - Resolving associations for [ai.alethio.babyface.domain.final_inspector.domain.FinalInspector#18]
org.hibernate.engine.internal.TwoPhaseLoad [doInitializeEntity] - Done materializing entity [ai.alethio.babyface.domain.final_inspector.domain.FinalInspector#18]
o.h.l.p.e.p.i.ResultSetProcessingContextImpl [createSubselects] - Skipping create subselects because there are fewer than 2 results, so query by key is more efficient.
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [release] - Releasing result set [HikariProxyResultSet@1560720478 wrapping com.mysql.jdbc.JDBC42ResultSet@427be06f]
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [close] - Closing result set [HikariProxyResultSet@1560720478 wrapping com.mysql.jdbc.JDBC42ResultSet@427be06f]
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [release] - Releasing statement [HikariProxyPreparedStatement@331696273 wrapping com.mysql.jdbc.JDBC42PreparedStatement@7474b512: select finalinspe0_.id as id2_1_0_, finalinspe0_.account_id as account_3_1_0_, finalinspe0_.address as address4_1_0_, finalinspe0_.contact_email as contact_5_1_0_, finalinspe0_.contact_name as contact_6_1_0_, finalinspe0_.detail_address as detail_a7_1_0_, finalinspe0_.mobile as mobile8_1_0_, finalinspe0_.phone as phone9_1_0_, finalinspe0_.zipcode as zipcode10_1_0_, finalinspe0_.create_date_time as create_11_1_0_, finalinspe0_.email as email12_1_0_, finalinspe0_.name as name13_1_0_, finalinspe0_.update_date_time as update_14_1_0_, finalinspe0_.dormant as dormant15_1_0_, finalinspe0_.slack_member_id as slack_m16_1_0_ from abstract_user_profile finalinspe0_ where finalinspe0_.id=18 and finalinspe0_.dtype='FinalInspector']
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [release] - HHH000387: ResultSet's statement was not registered
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [close] - Closing prepared statement [HikariProxyPreparedStatement@331696273 wrapping com.mysql.jdbc.JDBC42PreparedStatement@7474b512: select finalinspe0_.id as id2_1_0_, finalinspe0_.account_id as account_3_1_0_, finalinspe0_.address as address4_1_0_, finalinspe0_.contact_email as contact_5_1_0_, finalinspe0_.contact_name as contact_6_1_0_, finalinspe0_.detail_address as detail_a7_1_0_, finalinspe0_.mobile as mobile8_1_0_, finalinspe0_.phone as phone9_1_0_, finalinspe0_.zipcode as zipcode10_1_0_, finalinspe0_.create_date_time as create_11_1_0_, finalinspe0_.email as email12_1_0_, finalinspe0_.name as name13_1_0_, finalinspe0_.update_date_time as update_14_1_0_, finalinspe0_.dormant as dormant15_1_0_, finalinspe0_.slack_member_id as slack_m16_1_0_ from abstract_user_profile finalinspe0_ where finalinspe0_.id=18 and finalinspe0_.dtype='FinalInspector']
o.h.engine.jdbc.internal.JdbcCoordinatorImpl [afterStatementExecution] - Starting after statement execution processing [ON_CLOSE]
o.h.engine.internal.StatefulPersistenceContext [initializeNonLazyCollections] - Initializing non-lazy collections
o.h.l.e.plan.AbstractLoadPlanBasedEntityLoader [load] - Done entity load : ai.alethio.babyface.domain.final_inspector.domain.FinalInspector#18

EntityManager(=Session) close = detached 상태 
o.s.orm.jpa.support.OpenEntityManagerInViewFilter [doFilterInternal] - Closing JPA EntityManager in OpenEntityManagerInViewFilter
org.hibernate.internal.SessionImpl [close] - Closing session [466b0bdf-35c7-4512-9bce-44fff361a733]
o.h.engine.jdbc.internal.JdbcCoordinatorImpl [close] - Closing JDBC container [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl@302d2f8d]
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [releaseResources] - Releasing JDBC resources
o.h.r.jdbc.internal.LogicalConnectionManagedImpl [close] - Closing logical connection
o.h.r.jdbc.internal.ResourceRegistryStandardImpl [releaseResources] - Releasing JDBC resources
o.h.r.jdbc.internal.LogicalConnectionManagedImpl [close] - Logical connection closed

참고

https://tecoble.techcourse.co.kr/post/2020-09-20-entity-lifecycle-2/

https://stackoverflow.com/questions/30549489/what-is-this-spring-jpa-open-in-view-true-property-in-spring-boot

https://blog.kingbbode.com/27

https://deveric.tistory.com/86

https://stackoverflow.com/questions/33056952/openentitymanagerinviewfilter-annotation-config

https://hulint.tistory.com/31

https://happyer16.tistory.com/entry/스프링-요청request시-트랜잭션-시작은-어디서-할까

https://tecoble.techcourse.co.kr/post/2020-09-20-entity-lifecycle-2/