神奇的session in jpa

引言

再回顾一下问题场景：

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 挂掉了。

兹可谓一劳而久逸。暂费而永无宁者也。 ——班固《封燕然山铭》

一劳永逸，这是程序员最快乐的时候。