JPA Session 一勞永逸

引言

再回顧一下問題場景：

Iterable<Teacher> teachers = teacherRepository.findAll();
for (Teacher teacher : teachers) {
    logger.debug("教師: " + teacher.getName());

    for (Klass klass : teacher.getKlasses()) {
        logger.debug("班級: " + klass.getName());

        for (Student student : klass.getStudents()) {
            logger.debug("學生: " + student.getName());
        }
    }
}

在單元測試中跑這段代碼，是報錯的，no Session，說明執行完teacherRepository.findAll()以後，session就已經關閉了。繼續執行，session已經關閉，再去數據庫查教師關聯的班級信息，就錯了。

然而呢？把這段代碼再放到Service裏，寫一個接口，交給瀏覽器去調用，卻正常執行，說明session還在。

而後就一直研究爲何很差使？若是能把這個緣由分析明白，之後再遇到no session錯誤的時候就能夠一勞永逸了。

探究

調試

調試最簡單的方法就是中斷，可是咱水平還不行，也不知道JPA內部去找Hibernate怎麼調用的，中斷哪一個方法呢？

後臺發現了另外一種調試的方法，JPA的源碼中也是像咱們開發時常常寫日誌的，logger.debug()什麼的。

slf4j中經常使用的日誌級別就ERROR、WARN、INFO、DEBUG四種，咱們能夠將JPA的日誌級別設置爲DEBUG級別，這樣咱們就能夠根據日誌推測到JPA內部究竟是怎麼執行的了。

修改日誌級別

logging.level.org.springframework.orm.jpa=debug

修改配置文件，將JPA的日誌級別設置爲DEBUG。

在單元測試中執行

完整日誌：

2019-06-06 11:36:40.415 DEBUG 11391 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findAll]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly
2019-06-06 11:36:40.416 DEBUG 11391 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Opened new EntityManager [SessionImpl(1334204880<open>)] for JPA transaction
2019-06-06 11:36:40.429 DEBUG 11391 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@73b74615]
2019-06-06 11:36:40.449  INFO 11391 --- [           main] o.h.h.i.QueryTranslatorFactoryInitiator  : HHH000397: Using ASTQueryTranslatorFactory
Hibernate: select teacher0_.id as id1_2_, teacher0_.name as name2_2_ from teacher teacher0_
2019-06-06 11:36:40.598 DEBUG 11391 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2019-06-06 11:36:40.598 DEBUG 11391 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(1334204880<open>)]
2019-06-06 11:36:40.601 DEBUG 11391 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(1334204880<open>)] after transaction
2019-06-06 11:36:40.602 DEBUG 11391 --- [           main] com.yunzhiclub.jpa.JpaApplicationTests   : 教師: 張三

org.hibernate.LazyInitializationException: failed to lazily initialize a collection of role: com.yunzhiclub.jpa.entity.Teacher.klasses, could not initialize proxy - no Session

分析

Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findAll]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly
Opened new EntityManager [SessionImpl(1334204880<open>)] for JPA transaction
Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@73b74615]
HHH000397: Using ASTQueryTranslatorFactory
Hibernate: select teacher0_.id as id1_2_, teacher0_.name as name2_2_ from teacher teacher0_
Initiating transaction commit
Committing JPA transaction on EntityManager [SessionImpl(1334204880<open>)]

上來是先執行了一個事務，爲何會有事務呢？

JPA建立的倉庫實現是SimpleJpaRepository，咱們看看源碼：

實現類上添加了事務註解，並採用了默認的REQUIRED傳播級別。

若是當前存在事務，則使用當前事務。若是不存在任何事務，則建立一個新的事務。

當前不存在事務，因此是teacherRepository.findAll()方法本身建立的事務。

Hibernate: select teacher0_.id as id1_2_, teacher0_.name as name2_2_ from teacher teacher0_
Initiating transaction commit
Committing JPA transaction on EntityManager [SessionImpl(1334204880<open>)]
Closing JPA EntityManager [SessionImpl(1334204880<open>)] after transaction
教師: 張三

org.hibernate.LazyInitializationException: failed to lazily initialize a collection of role: com.yunzhiclub.jpa.entity.Teacher.klasses, could not initialize proxy - no Session

再接着看下面的日誌，執行了數據庫的查詢操做，提交了一個事務，而後Closing JPA EntityManager [SessionImpl(1334204880<open>)] after transaction。

事務執行以後，就關閉了EntityManager，也就是Hibernate中的Session。

Session is a hibernate-specific API, EntityManager is a standardized API for JPA.

EntityManager和Session仍是有一些差異的，可是咱們目前還未接觸到底層的實現，只須要把他們當成一個東西，只不過在不一樣領域叫法不一樣罷了。

在SpringMVC中執行

執行得很順利，完整日誌以下：

2019-06-06 11:58:28.788 DEBUG 11443 --- [nio-8080-exec-1] o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor
2019-06-06 11:58:28.800 DEBUG 11443 --- [nio-8080-exec-1] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(193939447<open>)] for JPA transaction
2019-06-06 11:58:28.800 DEBUG 11443 --- [nio-8080-exec-1] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findAll]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly
2019-06-06 11:58:28.808 DEBUG 11443 --- [nio-8080-exec-1] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@56eb5438]
2019-06-06 11:58:28.820  INFO 11443 --- [nio-8080-exec-1] o.h.h.i.QueryTranslatorFactoryInitiator  : HHH000397: Using ASTQueryTranslatorFactory
Hibernate: select teacher0_.id as id1_2_, teacher0_.name as name2_2_ from teacher teacher0_
2019-06-06 11:58:28.897 DEBUG 11443 --- [nio-8080-exec-1] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2019-06-06 11:58:28.898 DEBUG 11443 --- [nio-8080-exec-1] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(193939447<open>)]
2019-06-06 11:58:28.901 DEBUG 11443 --- [nio-8080-exec-1] o.s.orm.jpa.JpaTransactionManager        : Not closing pre-bound JPA EntityManager after transaction
2019-06-06 11:58:28.902 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 教師: 張三
Hibernate: select klasses0_.teacher_id as teacher_3_0_0_, klasses0_.id as id1_0_0_, klasses0_.id as id1_0_1_, klasses0_.name as name2_0_1_, klasses0_.teacher_id as teacher_3_0_1_ from klass klasses0_ where klasses0_.teacher_id=?
2019-06-06 11:58:28.915 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 班級: 軟件工程
Hibernate: select students0_.klass_id as klass_id4_1_0_, students0_.id as id1_1_0_, students0_.id as id1_1_1_, students0_.email as email2_1_1_, students0_.klass_id as klass_id4_1_1_, students0_.name as name3_1_1_ from student students0_ where students0_.klass_id=?
2019-06-06 11:58:28.917 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 學生: Hello Kitty
2019-06-06 11:58:28.917 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 學生: 史努比
2019-06-06 11:58:28.917 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 班級: 網絡工程
Hibernate: select students0_.klass_id as klass_id4_1_0_, students0_.id as id1_1_0_, students0_.id as id1_1_1_, students0_.email as email2_1_1_, students0_.klass_id as klass_id4_1_1_, students0_.name as name3_1_1_ from student students0_ where students0_.klass_id=?
2019-06-06 11:58:28.919 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 學生: 米老鼠
2019-06-06 11:58:28.919 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 學生: 唐老鴨
2019-06-06 11:58:28.919 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 教師: 李四
Hibernate: select klasses0_.teacher_id as teacher_3_0_0_, klasses0_.id as id1_0_0_, klasses0_.id as id1_0_1_, klasses0_.name as name2_0_1_, klasses0_.teacher_id as teacher_3_0_1_ from klass klasses0_ where klasses0_.teacher_id=?
2019-06-06 11:58:28.921 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 班級: 計算機科學與技術
Hibernate: select students0_.klass_id as klass_id4_1_0_, students0_.id as id1_1_0_, students0_.id as id1_1_1_, students0_.email as email2_1_1_, students0_.klass_id as klass_id4_1_1_, students0_.name as name3_1_1_ from student students0_ where students0_.klass_id=?
2019-06-06 11:58:28.923 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 學生: 哪吒
2019-06-06 11:58:28.923 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 學生: 小竹熊
2019-06-06 11:58:28.923 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 班級: 物聯網
Hibernate: select students0_.klass_id as klass_id4_1_0_, students0_.id as id1_1_0_, students0_.id as id1_1_1_, students0_.email as email2_1_1_, students0_.klass_id as klass_id4_1_1_, students0_.name as name3_1_1_ from student students0_ where students0_.klass_id=?
2019-06-06 11:58:28.925 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 學生: 喜羊羊
2019-06-06 11:58:28.925 DEBUG 11443 --- [nio-8080-exec-1] c.y.jpa.service.TeacherServiceImpl       : 學生: 灰太狼
2019-06-06 11:58:28.944 DEBUG 11443 --- [nio-8080-exec-1] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor

分析

Opening JPA EntityManager in OpenEntityManagerInViewInterceptor
Found thread-bound EntityManager [SessionImpl(193939447<open>)] for JPA transaction
Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findAll]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly
Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@56eb5438]
HHH000397: Using ASTQueryTranslatorFactory
Hibernate: select teacher0_.id as id1_2_, teacher0_.name as name2_2_ from teacher teacher0_
Initiating transaction commit
Committing JPA transaction on EntityManager [SessionImpl(193939447<open>)]

這段沒什麼說的，和上面同樣，建立事務，執行完提交事務。

Not closing pre-bound JPA EntityManager after transaction
教師: 張三
Hibernate: select klasses0_.teacher_id as teacher_3_0_0_, klasses0_.id as id1_0_0_, klasses0_.id as id1_0_1_, klasses0_.name as name2_0_1_, klasses0_.teacher_id as teacher_3_0_1_ from klass klasses0_ where klasses0_.teacher_id=?
班級: 軟件工程
Hibernate: select students0_.klass_id as klass_id4_1_0_, students0_.id as id1_1_0_, students0_.id as id1_1_1_, students0_.email as email2_1_1_, students0_.klass_id as klass_id4_1_1_, students0_.name as name3_1_1_ from student students0_ where students0_.klass_id=?
學生: Hello Kitty
學生: 史努比
班級: 網絡工程
Hibernate: select students0_.klass_id as klass_id4_1_0_, students0_.id as id1_1_0_, students0_.id as id1_1_1_, students0_.email as email2_1_1_, students0_.klass_id as klass_id4_1_1_, students0_.name as name3_1_1_ from student students0_ where students0_.klass_id=?
學生: 米老鼠
學生: 唐老鴨
教師: 李四
Hibernate: select klasses0_.teacher_id as teacher_3_0_0_, klasses0_.id as id1_0_0_, klasses0_.id as id1_0_1_, klasses0_.name as name2_0_1_, klasses0_.teacher_id as teacher_3_0_1_ from klass klasses0_ where klasses0_.teacher_id=?
班級: 計算機科學與技術
Hibernate: select students0_.klass_id as klass_id4_1_0_, students0_.id as id1_1_0_, students0_.id as id1_1_1_, students0_.email as email2_1_1_, students0_.klass_id as klass_id4_1_1_, students0_.name as name3_1_1_ from student students0_ where students0_.klass_id=?
學生: 哪吒
學生: 小竹熊
班級: 物聯網
Hibernate: select students0_.klass_id as klass_id4_1_0_, students0_.id as id1_1_0_, students0_.id as id1_1_1_, students0_.email as email2_1_1_, students0_.klass_id as klass_id4_1_1_, students0_.name as name3_1_1_ from student students0_ where students0_.klass_id=?
學生: 喜羊羊
學生: 灰太狼
Closing JPA EntityManager in OpenEntityManagerInViewInterceptor

這塊就有意思了。

第一行：Not closing pre-bound JPA EntityManager after transaction

最後一行：Closing JPA EntityManager in OpenEntityManagerInViewInterceptor

在事務以後沒有關閉Session，一直到最後，纔將Session關閉，因此沒出錯。

而在單元測試中呢？Closing JPA EntityManager [SessionImpl(1334204880<open>)] after transaction，事務執行以後就關閉了Session，因此出錯了。

緣由

找着關鍵了，Service裏好使是由於Session在findAll的事務執行完以後沒有關閉。

以前怎麼沒發現呢？StackOverflow上這老哥和我是同樣的問題：Hibernate jpa entity manager not being closed in spring service layer - StackOverflow

User和Address一對多。

我寫了一個getUser方法，惰性加載的一對多，可是爲何序列化的時候去找addresses的時候，它不報lazy initialization的錯誤呢？

這是回答，你們注意一下我圈起來的幾個關鍵詞：

OpenEntityManagerInViewInterceptor：在Spring Boot項目中，Session是歸OpenEntityManagerInViewInterceptor管理的，這個是幹什麼的呢？

它是確保EntityManager(Session)一直保持開啓的狀態，直到請求結束以後(complete request)。因此session在本次請求中，一直open着，惰性加載的數據隨便查。

若是你不想這麼幹，你能夠配置spring.jpa.open-in-view=false來禁用此行爲。

做

將spring.jpa.open-in-view配置爲false做一把。

果真，session關閉了，報錯位置在TeacherServiceImpl第28行，就是查詢惰性加載的klasses出錯了。

總結

從上週想到這個問題開始，到今天解決，也是花了許久的時間。

因此之後再遇到no session的問題，若是是在項目裏的，就先去想一想是否是complete request了，請求結束前，session一直有效。

若是是在單元測試中，就去想一想是否是事務配錯了，致使session掛掉了。

茲可謂一勞而久逸。暫費而永無寧者也。 ——班固《封燕然山銘》

一勞永逸，這是程序員最快樂的時候。