• Spring Data JPA想要学得好，缓存机制掌握好

    文章目录

    Spring Data JPA想要学得好，缓存机制掌握好

    本文章主要对JPA进行简单的介绍，主要重点在于JPA的一级缓存机制，会带领大家浅读一下具体实现的Hibernate中的源码。

    Hibernate、JPA与Spring Data JPA之间的关系

    JPA是一套规范，内部是有接口和抽象类组成的。hibernate是一套成熟的ORM框架，而且Hibernate实现了JPA规范，所以也可以称hibernate为JPA的一种实现方式，我们使用JPA的API编程，意味着站在更高的角度上看待问题（面向接口编程）Spring Data JPA是Spring提供的一套对JPA操作更加高级的封装，是在JPA规范下的专门用来进行数据持久化的解决方案。以上就是对hibernate、JPA与Spring Data JPA三者之间的关系说明。
    参考：详谈hibernate,jpa与spring data jpa三者之间的关系

    在这里插入图片描述

    所以虽然我们标题是《Spring Data JPA想要学得好，缓存机制掌握好》，但实际上这里我们在探讨的是具体实现——Hibernate的缓存

    JPA的EntityManager接口与Hibernate的Session接口

    在这里插入图片描述

    首先EntityManager和Session都是接口。

    然后Session是继承于EntityManager的。

    在这里插入图片描述

    所以可以理解为EntityManager是对JPA持久化上下文交互的抽象，而Session 接口是 Hibernate 向应用程序提供的操纵对数据库的最主要的接口, 它提供了基本的保存, 更新, 删除和加载Java 对象的方法。而Hibernate是JPA的具体实现，所以Session自然是继承于EntityManager

    然后我们可以看EntityManager具体的实现类其实是Hibernate相关的类

    在这里插入图片描述

    在这里插入图片描述

    参考： 比较JPA的EntityManager接口与Hibernate的Session接口

    Hibernate的缓存

    Hibernate缓存包括两大类：一级缓存和二级缓存。

    一级缓存又称为"Session的缓存"，它是内置的，不能被卸载（不能被卸载的意思就是这种缓存不具有可选性，必须有的功能，不可以取消session缓存）。由于Session对象的生命周期通常对应一个数据库事务或者一个应用事务，因此它的缓存是事务范围的缓存在第一级缓存中，持久化类的每个实例都具有唯一的OID。我们使用@Transactional 注解时，JpaTransactionManager会在开启事务前打开一个session，将事务绑定在这个session上，事务结束session关闭。

    二级缓存又称为"SessionFactory的缓存"，由于SessionFactory对象的生命周期和应用程序的整个过程对应，因此二级缓存是进程范围或者集群范围的缓存，有可能出现并发问题，因此需要采用适当的并发访问策略。第二级缓存是可选的，是一个可配置的插件，在默认情况下，SessionFactory不会启用这个插件，二级缓存应用场景局限性比较大，适用于数据要求的实时性和准确性不高、变动很少的情况。
    原文链接：https://blog.csdn.net/qq_34485381/article/details/107117550

    Hibernate的一级缓存（Session的缓存）

    本篇博文主要探讨的只是Hibernate的一级缓存，因为他是内置且必须的，而二级缓存基本很少使用。

    我们在使用Spring Data JPA的时候，其实都会使用到Hibernate的一级缓存，所以了解缓存机制就变得尤为重要，下面举一个例子来看看：

    @Transactional
public User test() {
List<ContactInfo> contactInfos = new ArrayList<>(List.of(ContactInfo.builder()
    .address("test address").phoneNumber("1234").build()));
User user = User.builder()
    .name("kevin").contactInfos(contactInfos).build();
contactInfos.get(0).setUser(user);
userRepository.save(user);
userRepository.findById(1L);
userRepository.findById(1L);
return user;
}

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11
    • 12

    上面这个事务方法中会执行几次select语句？是两次吗？不真正答案是0次。可能有人就很好奇，明明调用了两次findById方法，却没有执行select语句，这是为什么呢？其实就是因为使用到了我们的一级缓存。

    当我们执行save方法的时候，其实是会把保存后的数据存入到缓存中的，如下图：

    在这里插入图片描述

    浅读缓存源码解密缓存过程

    那可能有的小伙伴会好奇，那数据是缓存到了哪里呢？接下来我们就通过debug的方式，来看一下在保存还有后续的查询过程是怎样的。

    我们先来说结论，缓存的数据是存在SessionImpl类中的StatefulPersistenceContext persistenceContext 属性上。

    在这里插入图片描述

    在StatefulPersistenceContext类中，其中有一个HashMap entitiesByKey属性，这个entitiesByKey属性字段的作用就是用来缓存数据的，这个StatefulPersistenceContext类中还有其他一些 Java 集合, 这些 Java 集合构成了 Session 缓存。

    在这里插入图片描述

    这次debug我们主要关注这个entitiesByKey属性字段

    我们来看当我们执行userRepository.save(user);这句的时候，最终会把存入的数据加入到缓存中，通过调用StatefulPersistenceContext类中的addEntity方法，把数据存入到entitiesByKey属性字段上。当然不只是user数据会存入，级联的contactInfo的数据也是会存入的，这里我们就不过多展示了。

    在这里插入图片描述

    在这里插入图片描述

    然后当我们调用userRepository.findById(1L);方法的时候，会先从缓存中获取数据，缓存中没有才回去真正的执行数据库查询。这个时候会调用StatefulPersistenceContext类中的getEntity方法，根据key去获取我们真正缓存的对象。

    在这里插入图片描述

    第二次我们调用userRepository.findById(1L);方法的时候，跟第一次是一样的，也是会从缓存中获取数据。

    JPA的源码中也是像我们开发时经常写日志的，使用logger.debug()什么的。所以我们可以将JPA的日志级别设置为DEBUG级别，这样我们就可以根据日志推测到JPA内部到底是怎么执行的了。

    logging:
  level:
    org.hibernate.type.descriptor.sql.BasicBinder: trace
    org:
      springframework:
        orm:
          jpa: debug

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7

    然后我们可以看到控制台的执行结果如下：

    2022-08-12 11:18:22.542 DEBUG 5228 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.example.service.UserService.save2]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2022-08-12 11:18:22.543 DEBUG 5228 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Opened new EntityManager [SessionImpl(13193469)] for JPA transaction
2022-08-12 11:18:22.555 DEBUG 5228 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@2e243122]
2022-08-12 11:18:24.124 DEBUG 5228 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(13193469)] for JPA transaction
2022-08-12 11:18:24.124 DEBUG 5228 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
Hibernate: 
    insert 
    into
        user
        (name) 
    values
        (?)
2022-08-12 11:18:24.164 TRACE 5228 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [kevin]
2022-08-12 11:20:03.262  WARN 5228 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m7s864ms197µs100ns).
Hibernate: 
    insert 
    into
        contact_info
        (address, phone_number, uid) 
    values
        (?, ?, ?)
2022-08-12 11:20:03.267 TRACE 5228 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [test address]
2022-08-12 11:20:03.267 TRACE 5228 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [1234]
2022-08-12 11:20:03.268 TRACE 5228 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [BIGINT] - [1]
2022-08-12 11:21:00.872  WARN 5228 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=59s937ms26µs800ns).
2022-08-12 11:21:21.496 DEBUG 5228 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(13193469)] for JPA transaction
2022-08-12 11:21:21.496 DEBUG 5228 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 11:23:34.497  WARN 5228 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=2m2s354ms216µs200ns).
2022-08-12 11:23:36.406 DEBUG 5228 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(13193469)] for JPA transaction
2022-08-12 11:23:36.406 DEBUG 5228 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 11:25:11.600  WARN 5228 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m37s102ms703µs100ns).
2022-08-12 11:25:17.292 DEBUG 5228 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2022-08-12 11:25:17.292 DEBUG 5228 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(13193469)]
2022-08-12 11:25:19.667 DEBUG 5228 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(13193469)] after transaction

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11
    • 12
    • 13
    • 14
    • 15
    • 16
    • 17
    • 18
    • 19
    • 20
    • 21
    • 22
    • 23
    • 24
    • 25
    • 26
    • 27
    • 28
    • 29
    • 30
    • 31
    • 32
    • 33
    • 34

    从执行日志可以看出整个流程如下：

    1. 首先是开启了事务： Creating new transaction with name [org.example.service.UserService.save2]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
    2. 然后是创建了一个EntityManager：Opened new EntityManager [SessionImpl(13193469)] for JPA transaction
    3. 在执行完一系列操作之后，在最后提交了事务： Committing JPA transaction on EntityManager [SessionImpl(13193469)]
    4. 最后关闭了EntityManager：Closing JPA EntityManager [SessionImpl(13193469)] after transaction

    下面再举一个查询的例子，当我们在进行查询之后，其实也是会缓存到一级缓存里的。下面这个例子有两个事务，第一个事务是插入数据，而第二个事务是查询数据

    @Transactional
public User save() {
List<ContactInfo> contactInfos = new ArrayList<>(List.of(ContactInfo.builder()
    .address("test address").phoneNumber("1234").build()));
User user = User.builder()
    .name("kevin").contactInfos(contactInfos).build();
return userRepository.save(user);
}

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    @Transactional(readOnly = true)
public void read(){
userRepository.findById(1L);
User user = userRepository.findById(1L).get();
}

    • 1
    • 2
    • 3
    • 4
    • 5
    @Test
void testRead(){
    userService.save();
    userService.read();
}

    • 1
    • 2
    • 3
    • 4
    • 5

    在第二个事务方法中，我们连续执行了两次findById操作。那最终控制台执行了几次select操作呢？是两次还是0次还是1次？

    答案是1次。

    一样的我们来看最终输出的执行结果，之后我们在debug看看

    2022-08-12 14:02:54.122 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.example.service.UserService.save]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2022-08-12 14:02:54.122 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Opened new EntityManager [SessionImpl(449653268)] for JPA transaction
2022-08-12 14:02:54.132 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@7e305953]
2022-08-12 14:02:54.150 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(449653268)] for JPA transaction
2022-08-12 14:02:54.150 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
Hibernate: 
    insert 
    into
        user
        (name) 
    values
        (?)
2022-08-12 14:02:54.194 TRACE 22904 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [kevin]
Hibernate: 
    insert 
    into
        contact_info
        (address, phone_number, uid) 
    values
        (?, ?, ?)
2022-08-12 14:02:54.502 TRACE 22904 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [test address]
2022-08-12 14:02:54.502 TRACE 22904 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [1234]
2022-08-12 14:02:54.503 TRACE 22904 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [BIGINT] - [null]
2022-08-12 14:02:54.512 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2022-08-12 14:02:54.512 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(449653268)]
2022-08-12 14:02:54.557 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(449653268)] after transaction
2022-08-12 14:02:54.558 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.example.service.UserService.read]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly
2022-08-12 14:02:54.558 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Opened new EntityManager [SessionImpl(1881845799)] for JPA transaction
2022-08-12 14:02:54.564 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@1dab2cf5]
2022-08-12 14:02:54.564 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(1881845799)] for JPA transaction
2022-08-12 14:02:54.564 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
Hibernate: 
    select
        user0_.id as id1_1_0_,
        user0_.name as name2_1_0_ 
    from
        user user0_ 
    where
        user0_.id=?
2022-08-12 14:02:54.577 TRACE 22904 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [1]
2022-08-12 14:02:54.593 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(1881845799)] for JPA transaction
2022-08-12 14:02:54.593 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 14:02:54.594 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2022-08-12 14:02:54.594 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(1881845799)]
2022-08-12 14:02:54.599 DEBUG 22904 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(1881845799)] after transaction


    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11
    • 12
    • 13
    • 14
    • 15
    • 16
    • 17
    • 18
    • 19
    • 20
    • 21
    • 22
    • 23
    • 24
    • 25
    • 26
    • 27
    • 28
    • 29
    • 30
    • 31
    • 32
    • 33
    • 34
    • 35
    • 36
    • 37
    • 38
    • 39
    • 40
    • 41
    • 42
    • 43
    • 44
    • 45
    • 46

    从日志来看确实就是查询了一次数据库。因为从日志上看我们创建的EntityManager,或者说我们创建的Session是在事务级别的，从Opened new EntityManager [SessionImpl(449653268)] for JPA transaction 这一句可以看出来。所以我们的缓存当然也是在同一个事务下才是可见的。所以在第一个事务1中虽然save方法缓存了数据，但是在第二个事务中我们开启了一个新的session，所以我们并看不到事务1的缓存，所以去真实的查询了数据库，并缓存了下来，然后事务2的第二个findById就能从缓存中获取数据，并不需要去真实的查询数据库了。

    让我们可以debug来看看，建议自己动手理解更加深刻。

    在第一个findById执行过程中会把查询后的数据进行缓存，我们可以看到会走进StatefulPersistenceContext类中的addEntity方法

    在这里插入图片描述

    在第二个findById执行过程中发现缓存中有对应的数据就直接拿出来，并不需要再次查询数据库了。

    在这里插入图片描述

    Hibernate的一级缓存（Session的缓存）的作用

    从上面的例子来看，我们可以知道一级缓存最大的作用其实就是缓存的作用：减少访问数据库的频率。因为我们不想在代码中每次调用find方法，都需要真实的去查询数据库，或者是我们在保存完数据之后，我们也不需要直接去查询数据库获取数据，而是通过缓存就能获取到数据，这样可以大大减少我们对数据库的访问次数。但这仅仅只是缓存的其中一个作用，Hibernate的一级缓存还有一个作用就是用来同步缓存对象和数据库中的记录。

    Hibernate的一级缓存的作用有两个

    1. 减少访问数据库的频率。
    2. 保证缓存中的对象与数据库中的相关记录保持同步。

    在这里插入图片描述

    同步缓存中的对象

    前面我们都是讲了Hibernate的一级缓存中的第一个作用，现在我们来研究下它的第二个作用：保证缓存中的对象与数据库中的相关记录保持同步。

    我们来举一个例子，对上面的代码做一点小小的改造

    @Transactional(readOnly = true)
public void read(){
    userRepository.findById(1L);
    User user = userRepository.findById(1L).get();
    user.setName("test1111");
}

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6

    你们觉得上面的代码，最终会执行update语句吗？答案是不会出现update语句。我们可以直接看执行日志就可以看出来，但在看之前我们需要再设置一下我们日志级别，因为我们想关注更多的信息。

    logging:
  level:
    org.hibernate.type.descriptor.sql.BasicBinder: trace
    org:
      springframework:
        orm:
          jpa: debug
      hibernate:
        event:
          internal: trace

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10

    接下来我们来看执行的结果

    2022-08-12 15:44:47.961 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.example.service.UserService.save]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2022-08-12 15:44:47.962 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Opened new EntityManager [SessionImpl(443006127)] for JPA transaction
2022-08-12 15:44:47.972 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@171b0d3]
2022-08-12 15:44:47.990 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(443006127)] for JPA transaction
2022-08-12 15:44:47.991 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 15:44:48.000 TRACE 25408 --- [           main] o.hibernate.event.internal.EntityState   : Transient instance of: org.example.entity.User
2022-08-12 15:44:48.001 TRACE 25408 --- [           main] o.h.e.i.DefaultPersistEventListener      : Saving transient instance
2022-08-12 15:44:48.005 TRACE 25408 --- [           main] o.h.e.i.AbstractSaveEventListener        : Saving [org.example.entity.User#]
2022-08-12 15:44:48.024 TRACE 25408 --- [           main] o.hibernate.event.internal.WrapVisitor   : Wrapped collection in role: org.example.entity.User.contactInfos
Hibernate: 
    insert 
    into
        user
        (name) 
    values
        (?)
2022-08-12 15:44:48.042 TRACE 25408 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [kevin]
2022-08-12 15:44:48.064 TRACE 25408 --- [           main] o.hibernate.event.internal.EntityState   : Transient instance of: org.example.entity.ContactInfo
2022-08-12 15:44:48.065 TRACE 25408 --- [           main] o.h.e.i.DefaultPersistEventListener      : Saving transient instance
2022-08-12 15:44:48.065 TRACE 25408 --- [           main] o.h.e.i.AbstractSaveEventListener        : Saving [org.example.entity.ContactInfo#]
Hibernate: 
    insert 
    into
        contact_info
        (address, phone_number, uid) 
    values
        (?, ?, ?)
2022-08-12 15:44:48.065 TRACE 25408 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [test address]
2022-08-12 15:44:48.065 TRACE 25408 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [1234]
2022-08-12 15:44:48.066 TRACE 25408 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [BIGINT] - [null]
2022-08-12 15:44:48.075 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2022-08-12 15:44:48.075 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(443006127)]
2022-08-12 15:44:48.076 TRACE 25408 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing session
2022-08-12 15:44:48.076 DEBUG 25408 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing flush-time cascades
2022-08-12 15:44:48.077 TRACE 25408 --- [           main] o.hibernate.event.internal.EntityState   : Persistent instance of: org.example.entity.ContactInfo
2022-08-12 15:44:48.077 TRACE 25408 --- [           main] o.h.e.i.DefaultPersistEventListener      : Ignoring persistent instance
2022-08-12 15:44:48.077 DEBUG 25408 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Dirty checking collections
2022-08-12 15:44:48.078 TRACE 25408 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing entities and processing referenced collections
2022-08-12 15:44:48.081 TRACE 25408 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing unreferenced collections
2022-08-12 15:44:48.082 TRACE 25408 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Scheduling collection removes/(re)creates/updates
2022-08-12 15:44:48.084 DEBUG 25408 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
2022-08-12 15:44:48.084 DEBUG 25408 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections
2022-08-12 15:44:48.085 TRACE 25408 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Executing flush
2022-08-12 15:44:48.089 TRACE 25408 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Post flush
2022-08-12 15:44:48.098 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(443006127)] after transaction
2022-08-12 15:44:48.099 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.example.service.UserService.read]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly
2022-08-12 15:44:48.099 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Opened new EntityManager [SessionImpl(858872101)] for JPA transaction
2022-08-12 15:44:48.103 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@4628f386]
2022-08-12 15:44:48.103 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(858872101)] for JPA transaction
2022-08-12 15:44:48.104 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 15:44:48.111 TRACE 25408 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Loading entity: [org.example.entity.User#1]
2022-08-12 15:44:48.111 TRACE 25408 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Attempting to resolve: [org.example.entity.User#1]
2022-08-12 15:44:48.113 TRACE 25408 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Object not resolved in any cache: [org.example.entity.User#1]
Hibernate: 
    select
        user0_.id as id1_1_0_,
        user0_.name as name2_1_0_ 
    from
        user user0_ 
    where
        user0_.id=?
2022-08-12 15:44:48.117 TRACE 25408 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [1]
2022-08-12 15:44:48.138 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(858872101)] for JPA transaction
2022-08-12 15:44:48.138 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 15:44:48.138 TRACE 25408 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Loading entity: [org.example.entity.User#1]
2022-08-12 15:44:48.138 TRACE 25408 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Attempting to resolve: [org.example.entity.User#1]
2022-08-12 15:44:48.138 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2022-08-12 15:44:48.138 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(858872101)]
2022-08-12 15:44:48.151 DEBUG 25408 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(858872101)] after transaction

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11
    • 12
    • 13
    • 14
    • 15
    • 16
    • 17
    • 18
    • 19
    • 20
    • 21
    • 22
    • 23
    • 24
    • 25
    • 26
    • 27
    • 28
    • 29
    • 30
    • 31
    • 32
    • 33
    • 34
    • 35
    • 36
    • 37
    • 38
    • 39
    • 40
    • 41
    • 42
    • 43
    • 44
    • 45
    • 46
    • 47
    • 48
    • 49
    • 50
    • 51
    • 52
    • 53
    • 54
    • 55
    • 56
    • 57
    • 58
    • 59
    • 60
    • 61
    • 62
    • 63
    • 64
    • 65
    • 66
    • 67
    • 68
    • 69

    这里不先讲为什么，我们先再改造一下我们的代码，然后看看执行结果：

    @Transactional
public void read(){
    userRepository.findById(1L);
    User user = userRepository.findById(1L).get();
    user.setName("test1111");
}

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6

    你们猜这次会有update语句吗？聪明的小伙伴肯定会说有，没错，答案就是会有update语句

    我们来看一下结果

    2022-08-12 15:52:11.719 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.example.service.UserService.save]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2022-08-12 15:52:11.720 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Opened new EntityManager [SessionImpl(8972378)] for JPA transaction
2022-08-12 15:52:11.732 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@6abca7a6]
2022-08-12 15:52:11.748 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(8972378)] for JPA transaction
2022-08-12 15:52:11.748 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 15:52:11.761 TRACE 10668 --- [           main] o.hibernate.event.internal.EntityState   : Transient instance of: org.example.entity.User
2022-08-12 15:52:11.762 TRACE 10668 --- [           main] o.h.e.i.DefaultPersistEventListener      : Saving transient instance
2022-08-12 15:52:11.767 TRACE 10668 --- [           main] o.h.e.i.AbstractSaveEventListener        : Saving [org.example.entity.User#]
2022-08-12 15:52:11.783 TRACE 10668 --- [           main] o.hibernate.event.internal.WrapVisitor   : Wrapped collection in role: org.example.entity.User.contactInfos
Hibernate: 
    insert 
    into
        user
        (name) 
    values
        (?)
2022-08-12 15:52:11.801 TRACE 10668 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [kevin]
2022-08-12 15:52:11.862 TRACE 10668 --- [           main] o.hibernate.event.internal.EntityState   : Transient instance of: org.example.entity.ContactInfo
2022-08-12 15:52:11.863 TRACE 10668 --- [           main] o.h.e.i.DefaultPersistEventListener      : Saving transient instance
2022-08-12 15:52:11.863 TRACE 10668 --- [           main] o.h.e.i.AbstractSaveEventListener        : Saving [org.example.entity.ContactInfo#]
Hibernate: 
    insert 
    into
        contact_info
        (address, phone_number, uid) 
    values
        (?, ?, ?)
2022-08-12 15:52:11.863 TRACE 10668 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [test address]
2022-08-12 15:52:11.863 TRACE 10668 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [1234]
2022-08-12 15:52:11.864 TRACE 10668 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [BIGINT] - [null]
2022-08-12 15:52:11.872 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2022-08-12 15:52:11.872 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(8972378)]
2022-08-12 15:52:11.872 TRACE 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing session
2022-08-12 15:52:11.872 DEBUG 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing flush-time cascades
2022-08-12 15:52:11.874 TRACE 10668 --- [           main] o.hibernate.event.internal.EntityState   : Persistent instance of: org.example.entity.ContactInfo
2022-08-12 15:52:11.874 TRACE 10668 --- [           main] o.h.e.i.DefaultPersistEventListener      : Ignoring persistent instance
2022-08-12 15:52:11.874 DEBUG 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Dirty checking collections
2022-08-12 15:52:11.875 TRACE 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing entities and processing referenced collections
2022-08-12 15:52:11.878 TRACE 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing unreferenced collections
2022-08-12 15:52:11.878 TRACE 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Scheduling collection removes/(re)creates/updates
2022-08-12 15:52:11.880 DEBUG 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
2022-08-12 15:52:11.881 DEBUG 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections
2022-08-12 15:52:11.882 TRACE 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Executing flush
2022-08-12 15:52:11.885 TRACE 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Post flush
2022-08-12 15:52:11.904 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(8972378)] after transaction
2022-08-12 15:52:11.905 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.example.service.UserService.read]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2022-08-12 15:52:11.905 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Opened new EntityManager [SessionImpl(794042208)] for JPA transaction
2022-08-12 15:52:11.908 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@1dcc0bb8]
2022-08-12 15:52:11.908 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(794042208)] for JPA transaction
2022-08-12 15:52:11.909 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 15:52:11.915 TRACE 10668 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Loading entity: [org.example.entity.User#1]
2022-08-12 15:52:11.915 TRACE 10668 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Attempting to resolve: [org.example.entity.User#1]
2022-08-12 15:52:11.918 TRACE 10668 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Object not resolved in any cache: [org.example.entity.User#1]
Hibernate: 
    select
        user0_.id as id1_1_0_,
        user0_.name as name2_1_0_ 
    from
        user user0_ 
    where
        user0_.id=?
2022-08-12 15:52:11.922 TRACE 10668 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [1]
2022-08-12 15:52:11.935 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(794042208)] for JPA transaction
2022-08-12 15:52:11.936 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 15:52:11.936 TRACE 10668 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Loading entity: [org.example.entity.User#1]
2022-08-12 15:52:11.936 TRACE 10668 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Attempting to resolve: [org.example.entity.User#1]
2022-08-12 15:52:11.936 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2022-08-12 15:52:11.936 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(794042208)]
2022-08-12 15:52:11.936 TRACE 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing session
2022-08-12 15:52:11.936 DEBUG 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing flush-time cascades
2022-08-12 15:52:11.936 DEBUG 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Dirty checking collections
2022-08-12 15:52:11.936 TRACE 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing entities and processing referenced collections
2022-08-12 15:52:11.937 TRACE 10668 --- [           main] o.h.e.i.DefaultFlushEntityEventListener  : Found dirty properties [[org.example.entity.User#1]] : [name]
2022-08-12 15:52:11.937 TRACE 10668 --- [           main] o.h.e.i.DefaultFlushEntityEventListener  : Updating entity: [org.example.entity.User#1]
2022-08-12 15:52:11.937 TRACE 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing unreferenced collections
2022-08-12 15:52:11.937 TRACE 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Scheduling collection removes/(re)creates/updates
2022-08-12 15:52:11.937 DEBUG 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
2022-08-12 15:52:11.938 DEBUG 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 (re)creations, 0 updates, 0 removals to 1 collections
2022-08-12 15:52:11.938 TRACE 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Executing flush
Hibernate: 
    update
        user 
    set
        name=? 
    where
        id=?
2022-08-12 15:52:11.944 TRACE 10668 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [test1111]
2022-08-12 15:52:11.944 TRACE 10668 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [BIGINT] - [1]
2022-08-12 15:52:11.963 TRACE 10668 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Post flush
2022-08-12 15:52:12.029 DEBUG 10668 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(794042208)] after transaction


    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11
    • 12
    • 13
    • 14
    • 15
    • 16
    • 17
    • 18
    • 19
    • 20
    • 21
    • 22
    • 23
    • 24
    • 25
    • 26
    • 27
    • 28
    • 29
    • 30
    • 31
    • 32
    • 33
    • 34
    • 35
    • 36
    • 37
    • 38
    • 39
    • 40
    • 41
    • 42
    • 43
    • 44
    • 45
    • 46
    • 47
    • 48
    • 49
    • 50
    • 51
    • 52
    • 53
    • 54
    • 55
    • 56
    • 57
    • 58
    • 59
    • 60
    • 61
    • 62
    • 63
    • 64
    • 65
    • 66
    • 67
    • 68
    • 69
    • 70
    • 71
    • 72
    • 73
    • 74
    • 75
    • 76
    • 77
    • 78
    • 79
    • 80
    • 81
    • 82
    • 83
    • 84
    • 85
    • 86
    • 87
    • 88
    • 89
    • 90
    • 91

    我们可以对比一下两段代码的区别就是是否设置了@Transactional(readOnly = true)

    我们可以对比一下两个执行结果的差别，细心的小伙伴从执行结果的最后一部分就可以看到差别了。如果是设置了@Transactional(readOnly = true),在最后是没有执行flush的操作，而设置了@Transactional会多出来flush的操作，然后在之后就会执行update的语句了。

    所以通过对比上面的例子我们可以发现，看起来是否有update语句跟是否执行了flush操作其实有很大的关系

    在这里插入图片描述

    但事实真的只是因为flush操作影响的吗？我们可以在改造一下我们的代码看看，既然你说是因为flush操作影响，那我们就手动调用一下看看

    @Transactional(readOnly = true)
  public void read(){
    userRepository.findById(1L);
    User user = userRepository.findById(1L).get();
    user.setName("test1111");
    userRepository.flush();
  }

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7

    上面的代码我们设置了@Transactional(readOnly = true)，同时还在最后手动调用了 userRepository.flush();操作，接下来我们看看执行结果。

    2022-08-12 16:50:55.630 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.example.service.UserService.save]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2022-08-12 16:50:55.631 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Opened new EntityManager [SessionImpl(658528347)] for JPA transaction
2022-08-12 16:50:55.641 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@321c01c2]
2022-08-12 16:50:55.657 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(658528347)] for JPA transaction
2022-08-12 16:50:55.658 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 16:50:55.669 TRACE 18488 --- [           main] o.hibernate.event.internal.EntityState   : Transient instance of: org.example.entity.User
2022-08-12 16:50:55.670 TRACE 18488 --- [           main] o.h.e.i.DefaultPersistEventListener      : Saving transient instance
2022-08-12 16:50:55.672 TRACE 18488 --- [           main] o.h.e.i.AbstractSaveEventListener        : Saving [org.example.entity.User#]
2022-08-12 16:50:55.690 TRACE 18488 --- [           main] o.hibernate.event.internal.WrapVisitor   : Wrapped collection in role: org.example.entity.User.contactInfos
Hibernate: 
    insert 
    into
        user
        (name) 
    values
        (?)
2022-08-12 16:50:55.708 TRACE 18488 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [kevin]
2022-08-12 16:50:55.737 TRACE 18488 --- [           main] o.hibernate.event.internal.EntityState   : Transient instance of: org.example.entity.ContactInfo
2022-08-12 16:50:55.737 TRACE 18488 --- [           main] o.h.e.i.DefaultPersistEventListener      : Saving transient instance
2022-08-12 16:50:55.737 TRACE 18488 --- [           main] o.h.e.i.AbstractSaveEventListener        : Saving [org.example.entity.ContactInfo#]
Hibernate: 
    insert 
    into
        contact_info
        (address, phone_number, uid) 
    values
        (?, ?, ?)
2022-08-12 16:50:55.737 TRACE 18488 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [VARCHAR] - [test address]
2022-08-12 16:50:55.737 TRACE 18488 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [VARCHAR] - [1234]
2022-08-12 16:50:55.738 TRACE 18488 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [BIGINT] - [null]
2022-08-12 16:50:55.747 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2022-08-12 16:50:55.748 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(658528347)]
2022-08-12 16:50:55.748 TRACE 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing session
2022-08-12 16:50:55.748 DEBUG 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing flush-time cascades
2022-08-12 16:50:55.749 TRACE 18488 --- [           main] o.hibernate.event.internal.EntityState   : Persistent instance of: org.example.entity.ContactInfo
2022-08-12 16:50:55.750 TRACE 18488 --- [           main] o.h.e.i.DefaultPersistEventListener      : Ignoring persistent instance
2022-08-12 16:50:55.750 DEBUG 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Dirty checking collections
2022-08-12 16:50:55.751 TRACE 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing entities and processing referenced collections
2022-08-12 16:50:55.755 TRACE 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing unreferenced collections
2022-08-12 16:50:55.755 TRACE 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Scheduling collection removes/(re)creates/updates
2022-08-12 16:50:55.758 DEBUG 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
2022-08-12 16:50:55.758 DEBUG 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections
2022-08-12 16:50:55.759 TRACE 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Executing flush
2022-08-12 16:50:55.762 TRACE 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Post flush
2022-08-12 16:50:55.770 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(658528347)] after transaction
2022-08-12 16:50:55.771 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [org.example.service.UserService.read]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly
2022-08-12 16:50:55.771 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Opened new EntityManager [SessionImpl(1230346437)] for JPA transaction
2022-08-12 16:50:55.774 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@624268ab]
2022-08-12 16:50:55.774 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(1230346437)] for JPA transaction
2022-08-12 16:50:55.775 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 16:50:55.780 TRACE 18488 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Loading entity: [org.example.entity.User#1]
2022-08-12 16:50:55.780 TRACE 18488 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Attempting to resolve: [org.example.entity.User#1]
2022-08-12 16:50:55.782 TRACE 18488 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Object not resolved in any cache: [org.example.entity.User#1]
Hibernate: 
    select
        user0_.id as id1_1_0_,
        user0_.name as name2_1_0_ 
    from
        user user0_ 
    where
        user0_.id=?
2022-08-12 16:50:55.785 TRACE 18488 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [1]
2022-08-12 16:50:55.797 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(1230346437)] for JPA transaction
2022-08-12 16:50:55.797 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 16:50:55.797 TRACE 18488 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Loading entity: [org.example.entity.User#1]
2022-08-12 16:50:55.797 TRACE 18488 --- [           main] o.h.e.internal.DefaultLoadEventListener  : Attempting to resolve: [org.example.entity.User#1]
2022-08-12 16:50:55.798 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(1230346437)] for JPA transaction
2022-08-12 16:50:55.798 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
2022-08-12 16:50:55.798 TRACE 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing session
2022-08-12 16:50:55.798 DEBUG 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing flush-time cascades
2022-08-12 16:50:55.798 DEBUG 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Dirty checking collections
2022-08-12 16:50:55.798 TRACE 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushing entities and processing referenced collections
2022-08-12 16:50:55.798 TRACE 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Processing unreferenced collections
2022-08-12 16:50:55.798 TRACE 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Scheduling collection removes/(re)creates/updates
2022-08-12 16:50:55.798 DEBUG 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
2022-08-12 16:50:55.798 DEBUG 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Flushed: 0 (re)creations, 0 updates, 0 removals to 1 collections
2022-08-12 16:50:55.798 TRACE 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Executing flush
2022-08-12 16:50:55.799 TRACE 18488 --- [           main] o.h.e.i.AbstractFlushingEventListener    : Post flush
2022-08-12 16:50:55.805 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2022-08-12 16:50:55.805 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(1230346437)]
2022-08-12 16:50:55.813 DEBUG 18488 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(1230346437)] after transaction


    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11
    • 12
    • 13
    • 14
    • 15
    • 16
    • 17
    • 18
    • 19
    • 20
    • 21
    • 22
    • 23
    • 24
    • 25
    • 26
    • 27
    • 28
    • 29
    • 30
    • 31
    • 32
    • 33
    • 34
    • 35
    • 36
    • 37
    • 38
    • 39
    • 40
    • 41
    • 42
    • 43
    • 44
    • 45
    • 46
    • 47
    • 48
    • 49
    • 50
    • 51
    • 52
    • 53
    • 54
    • 55
    • 56
    • 57
    • 58
    • 59
    • 60
    • 61
    • 62
    • 63
    • 64
    • 65
    • 66
    • 67
    • 68
    • 69
    • 70
    • 71
    • 72
    • 73
    • 74
    • 75
    • 76
    • 77
    • 78
    • 79
    • 80
    • 81
    • 82

    从执行结果看，我们最后也是进行了flush的操作，但是很遗憾的是并没有看到有update语句的生成。

    所以从上面的测试结果看起来就是，flush操作虽然能生成update语句，但是@Transactional(readOnly = true)情况下不管有没有flush操作都不会有任何的update语句。

    那我们对比一下这三个执行结果的区别到底在哪里？

    在这里插入图片描述

    我们可以看出来区别在于有没有执行flush，并且有没有检查出实体的改变(Dirty checking)

    但我们从上面也看出来flush的时机也不一样

    • 在设置了@Transactional(readOnly = true)不会进行自动flush操作
    • 设置了@Transactional(readOnly = false)会在事务commit时触发flush方法，所以在图中第二部分执行结果中，Flushing session 在Initiating transaction commit之后
    • 而对于手动执行flush操作的，也就是图中第三部分执行结果中，Flushing session会在Flushing session 在Initiating transaction commit之前。

    Flush与事务Commit的关系

    1. 在当前的事务执行commit时会触发flush方法
    2. 在当前的事务执行完commit时，如果隔离级别是可重复度，flush之后执行的update，insert，delete的操作会被其他的新事物看到最新的结果。
    3. 假设当前的事务是可重复度，手动执行flush方法之后，没有执行commit，那么其他事务是看不到最新值的变化的。但最新值变化对当前没有commit的事务是有效的。
    4. 如果执行了flush之后，当前事务发生了rollback操作，那么数据将会被回滚（数据库的机制）

    Flush的自动机制

    前面讲到了当前的事务执行commit时会触发flush方法，那么除此之外还有什么情况下会自动触发flush呢？

    1. 事务commit之前，即指执行transactionManager.commit()之前都会触发
    2. 执行任何的JPQL或者nativeSQL(代替直接操作Entity的方法)都会触发flush（可以理解为不走一级缓存，所以这个时候拿到的可能是旧数据，所以在此之前需要把当前的最新改动flush到DB）

    浅读源码解密flush方法

    接下来我们就通过DEBUG的方式，来简单带大家浅读一下源码，建议自己动手试试看。

    1. 我们先来看看，当我们设置了@Transactional(readOnly = true)的时候为啥不会进行自动flush操作？

    首先来看代码：

      @Transactional(readOnly = true)
  public void read(){
    userRepository.findById(1L);
    User user = userRepository.findById(1L).get();
    user.setName("test1111");
  }

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6

    然后我们通过DEBUG模式去运行

    在transaction commit之前，也就是在调用SessionImpl#beforeTransactionCompletion()的时候回去判断到底需不需要去auto flush

    在这里插入图片描述

    我们可以看到这里会判断当前的FlushMode是不是为MANUAL，如果是则不会进行flush操作

    在这里插入图片描述

    我们可以详细来看看这个FlushMode.MANUAL,从如下的注解中我们可以看出来，FlushMode.MANUAL是for ready only transactions。而默认值则是AUTO

    在这里插入图片描述

    那我们再来看看什么时候会把他设置为MANUAL呢？

    首先我们来看到JpaTransactionManager的doBegin方法，也就是在我们开始创建事务的时候，在这个方法中我们可以找到如下调用beginTransaction方法的地方。

    在这里插入图片描述

    这里会调用到具体实现类HibernateJpaDialect的beginTransaction方法

    在这里插入图片描述

    在这个方法中我们就会判断我们是否设置了readOnly=true,如果设置了就会把FlushMode设置为MANUAL

    所以从上面源码的DEBUG可以看出来，当我们设置了@Transactional(readOnly = true)的时候，是不会自动进行flush操作的。

    1. 当我们@Transactional(readOnly = true)，但是我们在代码中手动的进行flush的操作，为啥依然没有更新DB？

    一样的，我们先来看代码：

     @Transactional(readOnly = true)
  public void read(){
    userRepository.findById(1L);
    User user = userRepository.findById(1L).get();
    user.setName("test1111");
    userRepository.flush();
  }

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7

    然后我们使用DEBUG模式来运行

    在这里插入图片描述

    当我们调用repository的flush方法的时候，最终会调用到SessionImpl的flush方法，然后在里面会调用到FlushEventListener中的onFlush方法，实际上调用到的是DefaultFlushEventListener中的onFlush方法。

    在这里插入图片描述

    然后就会调用到DefaultFlushEventListener中的onFlush方法，这个方法里面我们会看到调用到了flushEverythingToExecutions方法，然后就会调用到AbstractFlushingEventListener中的flushEverythingToExecutions方法。然后我们可以看到会调用到flushEntities这个方法。

    然后我们在AbstractFlushingEventListener中的flushEntities方法中可以看到，调用了onFlushEntity方法

    在这里插入图片描述

    最后就会调用到DefaultFlushEntityEventListener的onFlushEntity方法中，在里面的isUpdateNecessary方法就会进行dirty checking，来判断实体是否发生了变化，如果发生了变化就要进行更新。

    在这里插入图片描述

    我们可以看到它传入了一个参数mightBeDirty, 我们来看这个参数是如何赋值的。我们进去requiresDirtyCheck方法中，然后继续看到isModifiableEntity方法，然后我们会发现，一旦当前的事务是read only就会返回false。

    在这里插入图片描述

    然后我们继续看isUpdateNecessary方法

    在这里插入图片描述

    从上面的代码可以看出来一旦当前的事务是read only的，isUpdateNecessary返回就是false，而且不会真正的去对比持久化对象的更新，所以也不会把更新的变化刷新到DB中。

    所以到这里我们可以总结一下，为什么我们在使用 Spring 时一定要注意把查询的操作定义成只读事务？
    因为一个本来只是查询的操作，却要在事务提交时进行flush操作，然后检查持久化对象的更新，看看进行了那些更新，要做这么多事情，这显然是不合理的。所以 hibernate 才给 session 的设置了这么一个 FlushMode ，那么只要这个 FlushMode 为 MANUAL ，就可以免去这些不必要的操作。所以只读事务避免了Hibernate的检测和同步持久对象的状态的更新,提升了运行性能，减少不必要的性能开销。

    1. 当我们设置了@Transactional是如何自动flush的？
     @Transactional
  public void read(){
    userRepository.findById(1L);
    User user = userRepository.findById(1L).get();
    user.setName("test1111");
  }

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6

    我们继续从上面的代码继续debug，也就是我们继续看isUpdateNecessary里面的代码，我们主要看里面的dirtyCheck方法

    在这里插入图片描述

    然后我们进到dirtyCheck方法中，主要看到persister.findDirty( values, loadedState, entity, session );这段代码，这段代码主要就是检查实体和快照中的不同。

    在这里插入图片描述

    然后我们可以看到这个方法最终走到了如下逻辑中，从代码中我们可以看到，其实是一个个字段进行比较的。

    在这里插入图片描述

    然后他就会进到scheduleUpdate方法中

    在这里插入图片描述

    scheduleUpdate方法中主要就是把EntityUpdateActon加入到ActionQueue中

    在这里插入图片描述

    然后就会就会执行flush操作

    在这里插入图片描述

    可以看到其实就是把ActionQueue中的action取出来一个个执行，然后就向DB发起了update的语句了。

    在这里插入图片描述

    上面只是以一种update的情况下来进行DEBUG的，带大家浅读了其中一些重要的代码逻辑，感兴趣的小伙伴可以更深入的进行研究。

    1. Flush的时候会改变执行顺序？

    如何重现这种顺序不一样的情况呢？可以参考：

    JPA踩坑系列之delete（二）

    spring-data-jpa踩坑 - delete-then-save唯一索引冲突问题

    简单的讲就是，spring-data-jpa在一个事务中,先调用delete方法,再调用save方法时,事务提交时,并不会先执行delete的语句,而是直接执行insert语句。

    那为什么不是按照我们预期的顺序，先执行insert然后在执行delete呢？

    问题产生的原因，跟我们上面浅读源码看到的ActionQueue有关。

    Hibernate 的所有操作都是以一个监听器组的形式在框架内部流转处理的，并且不会落入数据库，而是会保存到具体操作的 ActionQueue 中。ActionQueue 可以理解为具体的 SQL 操作的集合，ActionQueue 是有序的，当我们触发了 flush 事件的时候，ActionQueue 中的 SQL 才会依次落入 DB 中执行。
    参考：学习笔记: JPA 与 Hibernate

    在这里插入图片描述

    我可以带大家浅读一下源码，看看它到底是按照什么顺序去触发的呢？

    在上面DEBUG的过程中，我们也稍微带过了一下，我们可以看到DefaultFlushEventListener的onFlush方法，看到里面的performExecutions方法

    在这里插入图片描述

    在performExecutions方法中，我们可以看到actionQueue.executeActions();这句代码

    在这里插入图片描述

    在executeActions方法中我们可以看到，会遍历EXECUTABLE_LISTS_MAP,然后执行每一个action

    在这里插入图片描述

    所以我们主要关注点在于EXECUTABLE_LISTS_MAP里面存了什么，以及按什么顺序存的？

    我们直接点进去就可以看到EXECUTABLE_LISTS_MAP

    private static final LinkedHashMap<Class<? extends Executable>,ListProvider> EXECUTABLE_LISTS_MAP;
	static {
		EXECUTABLE_LISTS_MAP = new LinkedHashMap<Class<? extends Executable>,ListProvider>( 8 );

		EXECUTABLE_LISTS_MAP.put(
				OrphanRemovalAction.class,
				new ListProvider<OrphanRemovalAction>() {
					ExecutableList<OrphanRemovalAction> get(ActionQueue instance) {
						return instance.orphanRemovals;
					}
					ExecutableList<OrphanRemovalAction> init(ActionQueue instance) {
						// OrphanRemovalAction executables never require sorting.
						return instance.orphanRemovals = new ExecutableList<OrphanRemovalAction>( false );
					}
				}
		);
		EXECUTABLE_LISTS_MAP.put(
				AbstractEntityInsertAction.class,
				new ListProvider<AbstractEntityInsertAction>() {
					ExecutableList<AbstractEntityInsertAction> get(ActionQueue instance) {
						return instance.insertions;
					}
					ExecutableList<AbstractEntityInsertAction> init(ActionQueue instance) {
						if ( instance.isOrderInsertsEnabled() ) {
							return instance.insertions = new ExecutableList<AbstractEntityInsertAction>(
									new InsertActionSorter()
							);
						}
						else {
							return instance.insertions = new ExecutableList<AbstractEntityInsertAction>(
									false
							);
						}
					}
				}
		);
		EXECUTABLE_LISTS_MAP.put(
				EntityUpdateAction.class,
				new ListProvider<EntityUpdateAction>() {
					ExecutableList<EntityUpdateAction> get(ActionQueue instance) {
						return instance.updates;
					}
					ExecutableList<EntityUpdateAction> init(ActionQueue instance) {
						return instance.updates = new ExecutableList<EntityUpdateAction>(
								instance.isOrderUpdatesEnabled()
						);
					}
				}
		);
		EXECUTABLE_LISTS_MAP.put(
				QueuedOperationCollectionAction.class,
				new ListProvider<QueuedOperationCollectionAction>() {
					ExecutableList<QueuedOperationCollectionAction> get(ActionQueue instance) {
						return instance.collectionQueuedOps;
					}
					ExecutableList<QueuedOperationCollectionAction> init(ActionQueue instance) {
						return instance.collectionQueuedOps = new ExecutableList<QueuedOperationCollectionAction>(
								instance.isOrderUpdatesEnabled()
						);
					}
				}
		);
		EXECUTABLE_LISTS_MAP.put(
				CollectionRemoveAction.class,
				new ListProvider<CollectionRemoveAction>() {
					ExecutableList<CollectionRemoveAction> get(ActionQueue instance) {
						return instance.collectionRemovals;
					}
					ExecutableList<CollectionRemoveAction> init(ActionQueue instance) {
						return instance.collectionRemovals = new ExecutableList<CollectionRemoveAction>(
								instance.isOrderUpdatesEnabled()
						);
					}
				}
		);
		EXECUTABLE_LISTS_MAP.put(
				CollectionUpdateAction.class,
				new ListProvider<CollectionUpdateAction>() {
					ExecutableList<CollectionUpdateAction> get(ActionQueue instance) {
						return instance.collectionUpdates;
					}
					ExecutableList<CollectionUpdateAction> init(ActionQueue instance) {
						return instance.collectionUpdates = new ExecutableList<CollectionUpdateAction>(
								instance.isOrderUpdatesEnabled()
						);
					}
				}
		);
		EXECUTABLE_LISTS_MAP.put(
				CollectionRecreateAction.class,
				new ListProvider<CollectionRecreateAction>() {
					ExecutableList<CollectionRecreateAction> get(ActionQueue instance) {
						return instance.collectionCreations;
					}
					ExecutableList<CollectionRecreateAction> init(ActionQueue instance) {
						return instance.collectionCreations = new ExecutableList<CollectionRecreateAction>(
								instance.isOrderUpdatesEnabled()
						);
					}
				}
		);
		EXECUTABLE_LISTS_MAP.put(
				EntityDeleteAction.class,
				new ListProvider<EntityDeleteAction>() {
					ExecutableList<EntityDeleteAction> get(ActionQueue instance) {
						return instance.deletions;
					}
					ExecutableList<EntityDeleteAction> init(ActionQueue instance) {
						// EntityDeleteAction executables never require sorting.
						return instance.deletions = new ExecutableList<EntityDeleteAction>( false );
					}
				}
		);
	}

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11
    • 12
    • 13
    • 14
    • 15
    • 16
    • 17
    • 18
    • 19
    • 20
    • 21
    • 22
    • 23
    • 24
    • 25
    • 26
    • 27
    • 28
    • 29
    • 30
    • 31
    • 32
    • 33
    • 34
    • 35
    • 36
    • 37
    • 38
    • 39
    • 40
    • 41
    • 42
    • 43
    • 44
    • 45
    • 46
    • 47
    • 48
    • 49
    • 50
    • 51
    • 52
    • 53
    • 54
    • 55
    • 56
    • 57
    • 58
    • 59
    • 60
    • 61
    • 62
    • 63
    • 64
    • 65
    • 66
    • 67
    • 68
    • 69
    • 70
    • 71
    • 72
    • 73
    • 74
    • 75
    • 76
    • 77
    • 78
    • 79
    • 80
    • 81
    • 82
    • 83
    • 84
    • 85
    • 86
    • 87
    • 88
    • 89
    • 90
    • 91
    • 92
    • 93
    • 94
    • 95
    • 96
    • 97
    • 98
    • 99
    • 100
    • 101
    • 102
    • 103
    • 104
    • 105
    • 106
    • 107
    • 108
    • 109
    • 110
    • 111
    • 112
    • 113
    • 114

    我们可以看到，其实是按照如下顺序执行的。

    在这里插入图片描述

    所以很显然，我们可以看出来insert是会比delete先执行的。

    那我们如何解决这个问题呢？可以参考上面文章给出来的参考链接。

    总结

    JPA上手简单，让我们用操作对象的方式去操作数据库，所以实际上在框架层是做了很多东西，才让我们使用起来简单，但也因为使用不当或者不懂其中的原理让我们的代码出现了很多BUG。通过对JPA缓存机制的学习，让我们对JPA的实现原理有更深一步的认识。也希望通过本篇文章让大家对JPA的缓存机制有一定的了解，也帮助大家如何去DEBUG和阅读JPA底层的源码。JPA底层里面做了很多东西，包括我也没有全部了解，也正在学习的过程中，所以一篇文章没法带大家学完全部的内容，希望感兴趣的小伙伴可以更加深入的进行学习，如果有任何问题，欢迎指出，谢谢！

    参考

    详谈hibernate,jpa与spring data jpa三者之间的关系

    比较JPA的EntityManager接口与Hibernate的Session接口

    What is the difference between a Session and a Connection in Hibernate?

    Hibernate 深入Session

    Spring Data JPA的使用踩坑：关于缓存与快照

    Spring data jpa 缓存机制总结

    SPRING DATA JPA 缓存机制总结

    Spring Boot JPA 常见的那些坑

    Hibernate 复习笔记 (3)——Session 缓存（Hibernate 一级缓存）详解

    Hibernate 一级缓存导致某保险公司核心系统Weblogic中间件内存溢出的故障诊断

    Hibernate缓存策略

    JPA Session 一劳永逸

    JPA 查询问题探究

    JPA最佳实践

    JPA踩坑系列

    Hibernate 二级缓存

    源代码解读Spring只读事务与读写事务的性能的差别

    主题：解惑：在spring+hibernate中，只读事务是如何被优化的

    主题：Spring声明式事务管理源码解读之事务开始

    主题：Spring声明式事务管理源码解读之事务提交

    Spring Data JPA 原理与实战第十一天 Session相关、CompletableFuture、LazyInitializationException

    Spring Data JPA 视频

    学习笔记: JPA 与 Hibernate

    Spring Data JPA 原理与实战第十一天 JPAS事务、Hibernate和Persistence Context

    spring-data-jpa踩坑 - delete-then-save唯一索引冲突问题

  • 相关阅读:
    离线安装Levenshtein cannot import name ‘_levenshtein‘
    th:include的使用
    Excel 数据透视表教程大全之 07 数据透视表使用日期字段自动按月、年对销售数据进行分组（教程含数据）
    羧酸/氨基/羟基功能化修饰荧光聚苯乙烯AIE微球/AIE三苯胺衍生物荧光微球的研究与制备
    Linux-VI和VIM
    【excel】列转行
    [LeetCode85双周赛] [滑动窗口] [差分数组] [并查集]
    130. 被围绕的区域（Java、Union-Find）
    【DL】Linux服务器安装CUDA和CUDNN
    英特尔发布31.0.101.3430和31.0.101.2111新驱动
  • 原文地址：https://blog.csdn.net/cckevincyh/article/details/126646486