与 SQL 相比，Hibernate JPQL 查询非常慢
Hibernate JPQL query is very slow compared to SQL
在我的项目中，我遇到了一个 JPQL 查询问题，该查询大约需要 1.5 秒。当我直接在 PostgreSQL db 上执行从调试日志（执行 Hibernates 的同一日志）复制的 SQL 查询时，大约需要 15 毫秒。
@Service
@Transactional
@Slf4j
public class PersonSyncServiceImpl
extends HotelApiCommunicationService implements PersonSyncService {
[...]
private PersonLinked getLinkedPerson(CNPerson cnPerson, Obiekt obiekt) {
PersonLinked person = cnPerson.getPersonLinked();
if (person == null) {
var o = cnPerson;
List<PersonLinked> personList = personLinkedDao.findPersonLinkedByRecordData(
o.getPersonImiona(), o.getPersonNazwisko(), o.getPersonPesel(), o.getPersonEmail(), o.getPersonTelefon1());
person = personList.stream()
.findFirst().orElse(null);
if (person == null) {
person = createPersonLinkedFromCnPerson(cnPerson);
personLinkedDao.save(person);
}
cnPerson.setPersonLinked(person);
}
return person;
}
[...]
}
这一行有问题：
List<PersonLinked> personList = personLinkedDao.findPersonLinkedByRecordData(
o.getPersonImiona(), o.getPersonNazwisko(), o.getPersonPesel(), o.getPersonEmail(), o.getPersonTelefon1());
具有已定义查询的 Dao：
@Repository
@Transactional
public interface PersonLinkedDao extends JpaRepository<PersonLinked, Long> {
@Query("select o from PersonLinked o \n" +
"where o.personImiona = :imie and o.personNazwisko = :nazwisko \n" +
" and (o.personPesel = :pesel or o.personEmail = :email or o.personTelefon1 = :telefon)")
List<PersonLinked> findPersonLinkedByRecordData(
@Param("imie") String personImiona,
@Param("nazwisko") String personNazwisko,
@Param("pesel") String personPesel,
@Param("email") String personEmail,
@Param("telefon") String personTelefon);
}
SQL 来自 Hibernate 调试日志：
select [..]
from
person personlinke0_
where
personlinke0_.person_imiona=?
and personlinke0_.person_nazwisko=?
and (
personlinke0_.person_pesel=?
or personlinke0_.person_email=?
or personlinke0_.person_telefon1=?
)
当我在数据库上执行此查询时大约需要 15 毫秒，从代码执行大约需要 1.5 秒。我在代码中注释掉了这一行并且滞后消失了，所以问题肯定是这个 jpql select.
数据库连接配置：
spring.datasource.driver-class-name=org.postgresql.Driver
spring.jpa.database-platform=org.hibernate.dialect.PostgreSQL9Dialect
spring.datasource.url=jdbc:postgresql://192.168.1.200:5433/XXXXXXX
spring.datasource.username=XXXXX
spring.datasource.password=XXXXX
spring.jpa.show-sql=false
spring.jpa.properties.hibernate.format_sql=true
spring.jpa.properties.hibernate.jdbc.batch_size=50
spring.jpa.properties.hibernate.order_inserts=true
spring.jpa.properties.hibernate.generate_statistics=true
更新 1：
debug.log:
26-09-2020 16:06:36.130 [http-nio-8091-exec-2] DEBUG org.hibernate.SQL.logStatement -
select [...]
from
person personlinke0_
where
personlinke0_.person_imiona=?
and personlinke0_.person_nazwisko=?
and (
personlinke0_.person_pesel=?
or personlinke0_.person_email=?
or personlinke0_.person_telefon1=?
)
26-09-2020 16:06:36.130 [http-nio-8091-exec-2] DEBUG o.s.orm.jpa.JpaTransactionManager.doGetTransaction - Found thread-bound EntityManager [SessionImpl(1971671100<open>)] for JPA transaction
26-09-2020 16:06:36.130 [http-nio-8091-exec-2] DEBUG o.s.orm.jpa.JpaTransactionManager.handleExistingTransaction - Participating in existing transaction
26-09-2020 16:06:36.146 [http-nio-8091-exec-2] DEBUG o.s.orm.jpa.JpaTransactionManager.doGetTransaction - Found thread-bound EntityManager [SessionImpl(1971671100<open>)] for JPA transaction
26-09-2020 16:06:36.146 [http-nio-8091-exec-2] DEBUG o.s.orm.jpa.JpaTransactionManager.handleExistingTransaction - Participating in existing transaction
26-09-2020 16:06:36.146 [http-nio-8091-exec-2] DEBUG o.s.orm.jpa.JpaTransactionManager.doGetTransaction - Found thread-bound EntityManager [SessionImpl(1971671100<open>)] for JPA transaction
26-09-2020 16:06:36.146 [http-nio-8091-exec-2] DEBUG o.s.orm.jpa.JpaTransactionManager.handleExistingTransaction - Participating in existing transaction
26-09-2020 16:06:37.521 [http-nio-8091-exec-2] DEBUG org.hibernate.SQL.logStatement -
更新 2：
PersonLinked 实体 class:
@Entity
@Table(name = "person")
@Getter
@Setter
@SuperBuilder
@EqualsAndHashCode(of = "personId")
public class PersonLinked extends SCPerson {
@Id
@GeneratedValue(generator = "seq_person", strategy = GenerationType.SEQUENCE)
@SequenceGenerator(name = "seq_person", sequenceName = "seq_person", allocationSize = 30)
@Column(name = "OSOBA_ID", nullable = false)
private Long personId;
@OneToMany(mappedBy = "personLinked", fetch = FetchType.LAZY)
private List<CNPerson> cnPersonList;
@Tolerate
public PersonLinked() {
super();
}
@PrePersist
@Override
protected void preInsert() {
super.preInsert();
}
}
SCPerson class:
@MappedSuperclass
@Getter
@Setter
@SuperBuilder
public class SCPerson {
[...]
}
终于找到了解决办法，问题出在代码的另一部分。
在调用方法 getLinkedPerson() 之前，我有这行代码：
List<CNPerson> cnPersonList = cnPersonDao.findCnPersonNotLinkedWithPerson(obiekt.getLoid());
cnPersonList 在这里包含大约 70 000 个对象。
我改成了：
List<Integer> ids = cnPersonDao.findCnPersonIdsNotLinkedWithPerson(obiekt.getLoid());
问题描述如下：
Slow down during Hibernate context refresh. In case when you update
too many objects ORM engine (lets say Hibernate) has to sink them and
keep them in memory. Literally Hibernate must have all old states and
all new states of updated objects. Sometimes it does this quite
unoptimal.
You can indicate this using debug. Try to find the slowest place and
check what exactly is being invoked there. I might guess that it slows
down when hibernate updates state of the cache.
我认为是因为实体CNPerson和PersonLinked是链接的，但我不确定：
@ManyToOne(fetch = FetchType.LAZY,
cascade = {CascadeType.MERGE, CascadeType.PERSIST})
@JoinTable(name = "cnperson_links",
joinColumns = {@JoinColumn(name = "cnperson_loid")},
inverseJoinColumns = {@JoinColumn(name = "person_id")})
private PersonLinked personLinked;
在我的项目中，我遇到了一个 JPQL 查询问题，该查询大约需要 1.5 秒。当我直接在 PostgreSQL db 上执行从调试日志（执行 Hibernates 的同一日志）复制的 SQL 查询时，大约需要 15 毫秒。
@Service
@Transactional
@Slf4j
public class PersonSyncServiceImpl
extends HotelApiCommunicationService implements PersonSyncService {
[...]
private PersonLinked getLinkedPerson(CNPerson cnPerson, Obiekt obiekt) {
PersonLinked person = cnPerson.getPersonLinked();
if (person == null) {
var o = cnPerson;
List<PersonLinked> personList = personLinkedDao.findPersonLinkedByRecordData(
o.getPersonImiona(), o.getPersonNazwisko(), o.getPersonPesel(), o.getPersonEmail(), o.getPersonTelefon1());
person = personList.stream()
.findFirst().orElse(null);
if (person == null) {
person = createPersonLinkedFromCnPerson(cnPerson);
personLinkedDao.save(person);
}
cnPerson.setPersonLinked(person);
}
return person;
}
[...]
}
这一行有问题：
List<PersonLinked> personList = personLinkedDao.findPersonLinkedByRecordData(
o.getPersonImiona(), o.getPersonNazwisko(), o.getPersonPesel(), o.getPersonEmail(), o.getPersonTelefon1());
具有已定义查询的 Dao：
@Repository
@Transactional
public interface PersonLinkedDao extends JpaRepository<PersonLinked, Long> {
@Query("select o from PersonLinked o \n" +
"where o.personImiona = :imie and o.personNazwisko = :nazwisko \n" +
" and (o.personPesel = :pesel or o.personEmail = :email or o.personTelefon1 = :telefon)")
List<PersonLinked> findPersonLinkedByRecordData(
@Param("imie") String personImiona,
@Param("nazwisko") String personNazwisko,
@Param("pesel") String personPesel,
@Param("email") String personEmail,
@Param("telefon") String personTelefon);
}
SQL 来自 Hibernate 调试日志：
select [..]
from
person personlinke0_
where
personlinke0_.person_imiona=?
and personlinke0_.person_nazwisko=?
and (
personlinke0_.person_pesel=?
or personlinke0_.person_email=?
or personlinke0_.person_telefon1=?
)
当我在数据库上执行此查询时大约需要 15 毫秒，从代码执行大约需要 1.5 秒。我在代码中注释掉了这一行并且滞后消失了，所以问题肯定是这个 jpql select.
数据库连接配置：
spring.datasource.driver-class-name=org.postgresql.Driver
spring.jpa.database-platform=org.hibernate.dialect.PostgreSQL9Dialect
spring.datasource.url=jdbc:postgresql://192.168.1.200:5433/XXXXXXX
spring.datasource.username=XXXXX
spring.datasource.password=XXXXX
spring.jpa.show-sql=false
spring.jpa.properties.hibernate.format_sql=true
spring.jpa.properties.hibernate.jdbc.batch_size=50
spring.jpa.properties.hibernate.order_inserts=true
spring.jpa.properties.hibernate.generate_statistics=true
更新 1：
debug.log:
26-09-2020 16:06:36.130 [http-nio-8091-exec-2] DEBUG org.hibernate.SQL.logStatement -
select [...]
from
person personlinke0_
where
personlinke0_.person_imiona=?
and personlinke0_.person_nazwisko=?
and (
personlinke0_.person_pesel=?
or personlinke0_.person_email=?
or personlinke0_.person_telefon1=?
)
26-09-2020 16:06:36.130 [http-nio-8091-exec-2] DEBUG o.s.orm.jpa.JpaTransactionManager.doGetTransaction - Found thread-bound EntityManager [SessionImpl(1971671100<open>)] for JPA transaction
26-09-2020 16:06:36.130 [http-nio-8091-exec-2] DEBUG o.s.orm.jpa.JpaTransactionManager.handleExistingTransaction - Participating in existing transaction
26-09-2020 16:06:36.146 [http-nio-8091-exec-2] DEBUG o.s.orm.jpa.JpaTransactionManager.doGetTransaction - Found thread-bound EntityManager [SessionImpl(1971671100<open>)] for JPA transaction
26-09-2020 16:06:36.146 [http-nio-8091-exec-2] DEBUG o.s.orm.jpa.JpaTransactionManager.handleExistingTransaction - Participating in existing transaction
26-09-2020 16:06:36.146 [http-nio-8091-exec-2] DEBUG o.s.orm.jpa.JpaTransactionManager.doGetTransaction - Found thread-bound EntityManager [SessionImpl(1971671100<open>)] for JPA transaction
26-09-2020 16:06:36.146 [http-nio-8091-exec-2] DEBUG o.s.orm.jpa.JpaTransactionManager.handleExistingTransaction - Participating in existing transaction
26-09-2020 16:06:37.521 [http-nio-8091-exec-2] DEBUG org.hibernate.SQL.logStatement -
更新 2：
PersonLinked 实体 class:
@Entity
@Table(name = "person")
@Getter
@Setter
@SuperBuilder
@EqualsAndHashCode(of = "personId")
public class PersonLinked extends SCPerson {
@Id
@GeneratedValue(generator = "seq_person", strategy = GenerationType.SEQUENCE)
@SequenceGenerator(name = "seq_person", sequenceName = "seq_person", allocationSize = 30)
@Column(name = "OSOBA_ID", nullable = false)
private Long personId;
@OneToMany(mappedBy = "personLinked", fetch = FetchType.LAZY)
private List<CNPerson> cnPersonList;
@Tolerate
public PersonLinked() {
super();
}
@PrePersist
@Override
protected void preInsert() {
super.preInsert();
}
}
SCPerson class:
@MappedSuperclass
@Getter
@Setter
@SuperBuilder
public class SCPerson {
[...]
}
终于找到了解决办法，问题出在代码的另一部分。 在调用方法 getLinkedPerson() 之前，我有这行代码：
List<CNPerson> cnPersonList = cnPersonDao.findCnPersonNotLinkedWithPerson(obiekt.getLoid());
cnPersonList 在这里包含大约 70 000 个对象。
我改成了：
List<Integer> ids = cnPersonDao.findCnPersonIdsNotLinkedWithPerson(obiekt.getLoid());
问题描述如下：
Slow down during Hibernate context refresh. In case when you update too many objects ORM engine (lets say Hibernate) has to sink them and keep them in memory. Literally Hibernate must have all old states and all new states of updated objects. Sometimes it does this quite unoptimal.
You can indicate this using debug. Try to find the slowest place and check what exactly is being invoked there. I might guess that it slows down when hibernate updates state of the cache.
我认为是因为实体CNPerson和PersonLinked是链接的，但我不确定：
@ManyToOne(fetch = FetchType.LAZY,
cascade = {CascadeType.MERGE, CascadeType.PERSIST})
@JoinTable(name = "cnperson_links",
joinColumns = {@JoinColumn(name = "cnperson_loid")},
inverseJoinColumns = {@JoinColumn(name = "person_id")})
private PersonLinked personLinked;