Hibernate JPQL query is very slow compared to SQL

Question

In my project I have a problem with one JPQL query which takes about 1,5s. When I execute SQL query copied from debug log (the same one which executes Hibernates) direct on PostgreSQL db it takes about 15ms.

@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;
    }
[...]   
}   

Problem is with this line:

List<PersonLinked> personList = personLinkedDao.findPersonLinkedByRecordData(
        o.getPersonImiona(), o.getPersonNazwisko(), o.getPersonPesel(), o.getPersonEmail(), o.getPersonTelefon1());  

Dao with defined query:

@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 from Hibernate debug log:

select [..]
from
    person personlinke0_ 
where
    personlinke0_.person_imiona=? 
    and personlinke0_.person_nazwisko=? 
    and (
        personlinke0_.person_pesel=? 
        or personlinke0_.person_email=? 
        or personlinke0_.person_telefon1=?
    )

When I execute this query on database it takes about 15ms, execution from code takes about 1,5s. I commented out this line in code and lag disappeared, so for sure problem is this jpql select.

Database connection configuration:

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

UPDATE 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 - 

UPDATE 2:

PersonLinked entity 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 {
[...]
}

Answer 1

Finally I found a solution, problem was in another part of code. Before calling method getLinkedPerson() I had this line of code:

List<CNPerson> cnPersonList = cnPersonDao.findCnPersonNotLinkedWithPerson(obiekt.getLoid());

cnPersonList constans here about 70 000 objects.

I changed it to:

List<Integer> ids = cnPersonDao.findCnPersonIdsNotLinkedWithPerson(obiekt.getLoid());

Problem is described here: https://stackoverflow.com/a/46258045/9678458

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.

I think it is because entities CNPerson and PersonLinked are linked, but I am not sure:

@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;