Eager loading is triggering n 1 queries?-CodePudding

This question is specific to n 1 problem when using eager loading. The issue I am seeing is, n 1 problem is happening when child entity is defined to load eagerly, is this expected.

The entity relationships are as follows. A student belongs to one college, and a college can have multiple students. So there is ManyToOne relationship between Student --> College, and a OneToMany relationship between College --> Student.

The entities are as below.

@Entity
public class College {

    @Id
    @GeneratedValue
    private int collegeId;

    private String collegeName;

    @OneToMany(targetEntity = Student.class, mappedBy = "college", cascade = CascadeType.ALL, fetch = FetchType.EAGER)
    //as you can see students is loaded eagerly.
    private List<Student> students;

and

@Entity
public class Student {

    @Id
    @GeneratedValue
    private int studentId;

    private String studentName;

    @ManyToOne
    @JoinColumn(name = "collegeId_fk")
    private College college;

Now when I run below code,

collegeRepo.findAll().forEach( c -> System.err.println("college wit students: "   c.getStudents() ) );

I see multiple queries are triggered:

2022-02-21 07:12:32.242 TRACE 19824 --- [           main] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findAll]
Hibernate: 
    select
        college0_.college_id as college_1_1_,
        college0_.college_name as college_2_1_ 
    from
        college college0_
2022-02-21 07:12:32.497 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_1_1_] : [INTEGER]) - [1]
2022-02-21 07:12:32.500 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_2_1_] : [VARCHAR]) - [college1]
2022-02-21 07:12:32.501 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_1_1_] : [INTEGER]) - [2]
2022-02-21 07:12:32.501 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_2_1_] : [VARCHAR]) - [college2]
2022-02-21 07:12:32.501 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_1_1_] : [INTEGER]) - [3]
2022-02-21 07:12:32.501 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_2_1_] : [VARCHAR]) - [college3]
2022-02-21 07:12:32.501 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_1_1_] : [INTEGER]) - [4]
2022-02-21 07:12:32.502 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_2_1_] : [VARCHAR]) - [college4]
Hibernate: 
    select
        students0_.college_id_fk as college_3_12_0_,
        students0_.student_id as student_1_12_0_,
        students0_.student_id as student_1_12_1_,
        students0_.college_id_fk as college_3_12_1_,
        students0_.student_name as student_2_12_1_ 
    from
        student students0_ 
    where
        students0_.college_id_fk=?
2022-02-21 07:12:32.510 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [INTEGER] - [4]
Hibernate: 
    select
        students0_.college_id_fk as college_3_12_0_,
        students0_.student_id as student_1_12_0_,
        students0_.student_id as student_1_12_1_,
        students0_.college_id_fk as college_3_12_1_,
        students0_.student_name as student_2_12_1_ 
    from
        student students0_ 
    where
        students0_.college_id_fk=?
2022-02-21 07:12:32.744 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [INTEGER] - [3]
Hibernate: 
    select
        students0_.college_id_fk as college_3_12_0_,
        students0_.student_id as student_1_12_0_,
        students0_.student_id as student_1_12_1_,
        students0_.college_id_fk as college_3_12_1_,
        students0_.student_name as student_2_12_1_ 
    from
        student students0_ 
    where
        students0_.college_id_fk=?
2022-02-21 07:12:32.975 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [INTEGER] - [2]
2022-02-21 07:12:33.207 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_1_12_1_] : [INTEGER]) - [1]
2022-02-21 07:12:33.207 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_3_12_1_] : [INTEGER]) - [2]
2022-02-21 07:12:33.207 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_2_12_1_] : [VARCHAR]) - [student1]
2022-02-21 07:12:33.207 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_3_12_0_] : [INTEGER]) - [2]
2022-02-21 07:12:33.208 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_1_12_0_] : [INTEGER]) - [1]
2022-02-21 07:12:33.211 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_1_12_1_] : [INTEGER]) - [2]
2022-02-21 07:12:33.211 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_3_12_1_] : [INTEGER]) - [2]
2022-02-21 07:12:33.211 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_2_12_1_] : [VARCHAR]) - [student2]
2022-02-21 07:12:33.211 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_3_12_0_] : [INTEGER]) - [2]
2022-02-21 07:12:33.211 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_1_12_0_] : [INTEGER]) - [2]
2022-02-21 07:12:33.211 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_1_12_1_] : [INTEGER]) - [3]
2022-02-21 07:12:33.212 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_3_12_1_] : [INTEGER]) - [2]
2022-02-21 07:12:33.212 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_2_12_1_] : [VARCHAR]) - [student3]
2022-02-21 07:12:33.212 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_3_12_0_] : [INTEGER]) - [2]
2022-02-21 07:12:33.212 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_1_12_0_] : [INTEGER]) - [3]
2022-02-21 07:12:33.212 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_1_12_1_] : [INTEGER]) - [4]
2022-02-21 07:12:33.212 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_3_12_1_] : [INTEGER]) - [2]
2022-02-21 07:12:33.212 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_2_12_1_] : [VARCHAR]) - [student4]
2022-02-21 07:12:33.212 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_3_12_0_] : [INTEGER]) - [2]
2022-02-21 07:12:33.212 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_1_12_0_] : [INTEGER]) - [4]
2022-02-21 07:12:33.213 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_1_12_1_] : [INTEGER]) - [5]
2022-02-21 07:12:33.213 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_3_12_1_] : [INTEGER]) - [2]
2022-02-21 07:12:33.213 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_2_12_1_] : [VARCHAR]) - [student5]
2022-02-21 07:12:33.213 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_3_12_0_] : [INTEGER]) - [2]
2022-02-21 07:12:33.213 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_1_12_0_] : [INTEGER]) - [5]
2022-02-21 07:12:33.213 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_1_12_1_] : [INTEGER]) - [6]
2022-02-21 07:12:33.213 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_3_12_1_] : [INTEGER]) - [2]
2022-02-21 07:12:33.213 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_2_12_1_] : [VARCHAR]) - [student6]
2022-02-21 07:12:33.213 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([college_3_12_0_] : [INTEGER]) - [2]
2022-02-21 07:12:33.213 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([student_1_12_0_] : [INTEGER]) - [6]
Hibernate: 
    select
        students0_.college_id_fk as college_3_12_0_,
        students0_.student_id as student_1_12_0_,
        students0_.student_id as student_1_12_1_,
        students0_.college_id_fk as college_3_12_1_,
        students0_.student_name as student_2_12_1_ 
    from
        student students0_ 
    where
        students0_.college_id_fk=?
2022-02-21 07:12:33.214 TRACE 19824 --- [           main] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [INTEGER] - [1]
2022-02-21 07:12:33.449 TRACE 19824 --- [           main] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findAll]
college wit students: []
2022-02-21 07:12:33.450 TRACE 19824 --- [           main] o.s.t.i.TransactionInterceptor           : Completing transaction for [com.demo.MyRunner.run]
2022-02-21 07:12:33.450 DEBUG 19824 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2022-02-21 07:12:33.450 DEBUG 19824 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(8781131<open>)]
college wit students: [Student [studentId=1, studentName=student1, college=College [collegeId=2, collegeName=college2]], Student [studentId=2, studentName=student2, college=College [collegeId=2, collegeName=college2]], Student [studentId=3, studentName=student3, college=College [collegeId=2, collegeName=college2]], Student [studentId=4, studentName=student4, college=College [collegeId=2, collegeName=college2]], Student [studentId=5, studentName=student5, college=College [collegeId=2, collegeName=college2]], Student [studentId=6, studentName=student6, college=College [collegeId=2, collegeName=college2]]]
college wit students: []
college wit students: []
2022-02-21 07:12:33.919 DEBUG 19824 --- [           main] o.s.orm.jpa.JpaTransactionManager        : Closing JPA EntityManager [SessionImpl(8781131<open>)] after transaction

I am aware that using JOIN FETCH or NamedEntityGraph this can be solved.
However, I am more keen to understand if eager loading also (not just lazy loading) creates n 1 queries.

CodePudding user response：

Eager loading takes only effect when using EntityManager.find (which is used by the findById method in a Spring Data JPA method). It will create a query with a JOIN to obtain the additional fields, you can specify this by using the, Hibernate specific, @Fetch and @FetchMode.

When using the findAll it doesn't use the EntityManager.find but rather executes a JPQL, with JPQL it will only do what you specified it to do. In short it will not use the entity mapping to generate the query (apart from the field and table mapping). Because the findAll generates a simple SELECT x FROM entity x it will only load that, it will not load the joined tables. Those are now actually lazy.

You can see this behavior if you would write a simple test 1 with a findById and another with findAll and check the queries both generate. Or by doing a SELECT x FROM Entity x WHERE x.id=? as a query and do an EntityManager.find. You would expect the result to be the same, but it isn't.

NOTE: When using Criteria queries there is a difference (or at least there was) a difference in using JPA or the Hibernate Criteria API. The Criteria API (might) take into account more of the mappings.

CodePudding user response：

Eager loading only defines when the related entities are fetched but not how the entities are fetched (i.e. whether they are fetched by a join SQL or select SQL one by one separately).

The default behavior is that it will load the entities that need to be eager fetched by the select SQL one by one. So it can cause N 1 query problem which is demonstrated by your cases.

After you load the college list , the eager loading take effect which immediately load the students for each college by a select SQL one by one.