You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@openjpa.apache.org by "Vermeulen (JIRA)" <ji...@apache.org> on 2012/11/09 10:24:12 UTC
[jira] [Created] (OPENJPA-2296) N+1 select in eager fetching
relation fields of toOne relations
Vermeulen created OPENJPA-2296:
----------------------------------
Summary: N+1 select in eager fetching relation fields of toOne relations
Key: OPENJPA-2296
URL: https://issues.apache.org/jira/browse/OPENJPA-2296
Project: OpenJPA
Issue Type: Bug
Components: jdbc, kernel, performance
Affects Versions: 2.2.1
Reporter: Vermeulen
Priority: Critical
We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
Suppose we have entities Company 1..* Employee 1..* Project
According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
....
41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
....
In the first (efficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
In the second (inefficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Comment Edited] (OPENJPA-2296) N+1 select in eager fetching
relation fields of toOne relations
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13493853#comment-13493853 ]
Vermeulen edited comment on OPENJPA-2296 at 11/9/12 9:56 AM:
-------------------------------------------------------------
Note that explicitly doing a left join fetch query or setting fetchplan recursion depth does not help.
I am currently using the Eclipse debugger to localize the problem.
I suspect that the bug is inside JDBCStoreManager.createEagerSelects(). This is the method that determines the list of Eager relations that is shown in the trace. When Project - Employee is toOne it does consider Employee.projects but somehow skips it. When it is toMany, the relation is not skipped and it is added as eager.
I think at a high level in the EagerResultList we then see the consequence: the project relations are not yet fetched inside the "main query" of ResultObjectProvider.open(). After this, the while loop of EagerResultList adds Company entities and each call to load a Company entity has to do an actual database load to load the missing Employee.projects field of it's employee, instead of reusing the projects that should have been present in the context.
was (Author: slowstrider):
Note that explicitly doing a left join fetch query or setting fetchplan recursion depth does not help.
I am currently using the Eclipse debugger to localize the problem.
I suspect that the bug is inside JDBCStoreManager.createEagerSelects(). This is the method that determines the list of Eager relations that is shown in the trace. When Project - Employee is toOne it does consider Employee.projects but somehow skips it. When it is toMany, the relation is not skipped and it is added as eager.
I think at a high level in the EagerResultList we then see the consequence: the project relations are not yet fetched inside the "main query" of ResultObjectProvider.open(). After this, the while loop of EagerResultList adds entities and each call to load an Employee entity has to do an actual database load instead of reusing the entities that should be present in the context.
> N+1 select in eager fetching relation fields of toOne relations
> ---------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
>
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Updated] (OPENJPA-2296) N+1 select in eager fetching
relation fields of toOne relations
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Vermeulen updated OPENJPA-2296:
-------------------------------
Attachment: OPENJPA-2296-tests.zip
Added test cases that show the bug.
> N+1 select in eager fetching relation fields of toOne relations
> ---------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (OPENJPA-2296) N+1 select problems when eager
fetching OneToOne and ManyToOne fields
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13496936#comment-13496936 ]
Vermeulen commented on OPENJPA-2296:
------------------------------------
I think I have done all I possibly can to help solve this issue. Is there any OpenJPA developer willing to comment on the issue and explain whether or not this will be fixed?
> N+1 select problems when eager fetching OneToOne and ManyToOne fields
> ---------------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> EDIT: the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Updated] (OPENJPA-2296) N+1 select problems when eager
fetching OneToOne and ManyToOne fields
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Vermeulen updated OPENJPA-2296:
-------------------------------
Attachment: (was: OPENJPA-2296-tests.zip)
> N+1 select problems when eager fetching OneToOne and ManyToOne fields
> ---------------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> EDIT:
> - the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
> - The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue. (Somehow my fields are in the list of eager relations in OpenJPA's trace, but OpenJPA still uses a "load field" for them.)
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Comment Edited] (OPENJPA-2296) N+1 select in eager fetching
relation fields of toOne relations
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13493917#comment-13493917 ]
Vermeulen edited comment on OPENJPA-2296 at 11/9/12 11:35 AM:
--------------------------------------------------------------
Moving up the call stack I see that the eager select type used for fetching the field entities.Company.employee is indeeds set to join
by RelationFieldStrategy.selectEagerJoin. I think it is logical that a toOne uses a join instead of parallel select. However somehow further on this causes JDBCStoreManager.select to not consider parallel mode anymore for any of the relation fields of Employee. This can be seen where it calls createEagerSelects using the line
eager = Math.min(eager, fetch.getEagerFetchMode())
which results in JOIN, not parallel. Somehow this also doesn't result in an efficient SQL with join but gives the N+1 select.
I suspect that this problem may have been introduced when someone tried to prevent other bugs. The RelationFieldStrategy.selectEagerJoin that restricts the eager select mode to join has this comment (already in oldest version of svn):
// limit the eager mode to single on recursive eager fetching b/c
// at this point the select has been modified and an attempt to
// clone it for a to-many eager select can result in a clone that
// produces invalid SQL
I am now giving up my debugging because I really have insufficient knowledge of OpenJPA to know how to proceed from this without introducing new bugs. But I think I have provided more than enough information for an active OpenJPA committer to proceed from here to solve the problem for which I would be very grateful.
was (Author: slowstrider):
Moving up the call stack I see that the eager select type used for fetching the field entities.Company.employee is indeeds set to join
by RelationFieldStrategy.selectEagerJoin. I think it is logical that a toOne uses a join instead of parallel select. However somehow further on this causes JDBCStoreManager.select to not consider parallel mode anymore for any of the relation fields of Employee. This can be seen where it calls createEagerSelects using the line
eager = Math.min(eager, fetch.getEagerFetchMode())
which results in JOIN, not parallel. Somehow this also doesn't result in an efficient SQL with join but gives the N+1 select.
I suspect that this problem may have been introduced when someone fixed another bug. The RelationFieldStrategy.selectEagerJoin that restricts the eager select mode to join has this comment:
// limit the eager mode to single on recursive eager fetching b/c
// at this point the select has been modified and an attempt to
// clone it for a to-many eager select can result in a clone that
// produces invalid SQL
I am now giving up my debugging because I really have insufficient knowledge of OpenJPA to know how to proceed from this without introducing new bugs. But I think I have provided more than enough information for an active OpenJPA committer to proceed from here to solve the problem for which I would be very grateful.
> N+1 select in eager fetching relation fields of toOne relations
> ---------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
>
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (OPENJPA-2296) N+1 select problems when eager
fetching OneToOne and ManyToOne fields
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13497953#comment-13497953 ]
Vermeulen commented on OPENJPA-2296:
------------------------------------
Perhaps the problem with bidirectional can be seen as a variation of the main Company - Project - Employee example. We have A *..1 B 1..* C, but C is equal to A.
Are there technical limitations why this cannot be efficiently fetched?
> N+1 select problems when eager fetching OneToOne and ManyToOne fields
> ---------------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> EDIT:
> - an N+1 select problem also always occurs when eagerly fetching a ManyToOne field that is bidirectional (see TestManyOneEagerSQL)
> - The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue. (Somehow my fields are in the list of eager relations in OpenJPA's trace, but OpenJPA still uses a "load field" for them.)
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Updated] (OPENJPA-2296) N+1 select problems when eager
fetching OneToOne and ManyToOne fields
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Vermeulen updated OPENJPA-2296:
-------------------------------
Summary: N+1 select problems when eager fetching OneToOne and ManyToOne fields (was: N+1 select in eager fetching relation fields of toOne relations)
> N+1 select problems when eager fetching OneToOne and ManyToOne fields
> ---------------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> EDIT: the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (OPENJPA-2296) N+1 select in eager fetching
relation fields of toOne relations
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13493929#comment-13493929 ]
Vermeulen commented on OPENJPA-2296:
------------------------------------
Perhaps the issue can also be summarized as: as soon as the fetch strategy JDBCFetchConfiguration.EAGER_JOIN is selected, parallel select cannot be used anymore for entities in the entire subgraph (unless I interfere with the debugger). Unfortunately this van have a huge impact.
> N+1 select in eager fetching relation fields of toOne relations
> ---------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
>
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Updated] (OPENJPA-2296) N+1 select problems when eager
fetching OneToOne and ManyToOne fields
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Vermeulen updated OPENJPA-2296:
-------------------------------
Description:
EDIT:
- the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
- The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue.
We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
Suppose we have entities Company 1..* Employee 1..* Project
According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
....
41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
....
In the first (efficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
In the second (inefficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
was:
EDIT: the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
Suppose we have entities Company 1..* Employee 1..* Project
According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
....
41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
....
In the first (efficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
In the second (inefficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
> N+1 select problems when eager fetching OneToOne and ManyToOne fields
> ---------------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> EDIT:
> - the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
> - The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue.
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Comment Edited] (OPENJPA-2296) N+1 select in eager fetching
relation fields of toOne relations
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13496328#comment-13496328 ]
Vermeulen edited comment on OPENJPA-2296 at 11/13/12 5:20 PM:
--------------------------------------------------------------
Added OpenJPA test cases that show the bug (TestRecursiveEagerSQL.java).
Note that the N+1 select problem also occurs for ManyToOne when we only have two entities. E.g. A OneToMany B and when the ManyToOne relation from B to A is eager and we select B: then for each B it's A is loaded using a separate query, see TestManyOneEagerSQL.java. For A OneToOne B the problem does not occur, see TestOneOneEagerSQL.java.
I also found a partial fix: it can be fixed for the parallel eager select strategy by having RelationFieldStrategy.selectEagerJoin not limit recursive eager fetching to JOIN. I ran all tests in persistence-jdbc and it does result in the existing TestManyEagerSQL failing with duplicates in the list, perhaps this can be fixed using DISTINCT? (TestJPQLSubquery also fails but only because it is too sensitive to the generated SQL and is easily adjusted).
The join eager select strategy is not used at JDBCStoreManager.createEagerSelects because
- boolean hasJoin = fetch.hasJoin(fms[i].getFullName(false)); is false
- inEagerJoin = true (select query already has an eager to-one join)
I do not know if this can be fixed as well.
Finally a workaround can be done by using cached entities in the entity manager context. Simply select all entities that are otherwise loaded by their id as in the "load field" trace.
For the Company - Employee - Project example this would mean performing the query "SELECT e FROM Employee e" before the actual query.
was (Author: slowstrider):
Added OpenJPA test cases that show the bug.
> N+1 select in eager fetching relation fields of toOne relations
> ---------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Updated] (OPENJPA-2296) N+1 select problems when eager
fetching OneToOne and ManyToOne fields
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Vermeulen updated OPENJPA-2296:
-------------------------------
Attachment: OPENJPA-2296-tests.zip
Fixed an error in ManyBToOneA test.
Added an Order ManyToOne Customer example. This shows that OpenJPA DOES use only one query to fetch orders and their customers in case the relation is not bidirectional. However when making it bidirectional it uses "load field orders" for each customer.
> N+1 select problems when eager fetching OneToOne and ManyToOne fields
> ---------------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> EDIT:
> - the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
> - The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue. (Somehow my fields are in the list of eager relations in OpenJPA's trace, but OpenJPA still uses a "load field" for them.)
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Updated] (OPENJPA-2296) N+1 select problems when eager
fetching OneToOne and ManyToOne fields
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Vermeulen updated OPENJPA-2296:
-------------------------------
Description:
EDIT:
- an N+1 select problem also always occurs when eagerly fetching a ManyToOne field that is bidirectional (see TestManyOneEagerSQL)
- The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue. (Somehow my fields are in the list of eager relations in OpenJPA's trace, but OpenJPA still uses a "load field" for them.)
We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
Suppose we have entities Company 1..* Employee 1..* Project
According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
....
41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
....
In the first (efficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
In the second (inefficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
was:
EDIT:
- the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
- The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue. (Somehow my fields are in the list of eager relations in OpenJPA's trace, but OpenJPA still uses a "load field" for them.)
We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
Suppose we have entities Company 1..* Employee 1..* Project
According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
....
41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
....
In the first (efficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
In the second (inefficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
> N+1 select problems when eager fetching OneToOne and ManyToOne fields
> ---------------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> EDIT:
> - an N+1 select problem also always occurs when eagerly fetching a ManyToOne field that is bidirectional (see TestManyOneEagerSQL)
> - The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue. (Somehow my fields are in the list of eager relations in OpenJPA's trace, but OpenJPA still uses a "load field" for them.)
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Comment Edited] (OPENJPA-2296) N+1 select in eager fetching
relation fields of toOne relations
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13496328#comment-13496328 ]
Vermeulen edited comment on OPENJPA-2296 at 11/13/12 5:03 PM:
--------------------------------------------------------------
Added OpenJPA test cases that show the bug.
was (Author: slowstrider):
Added test cases that show the bug.
> N+1 select in eager fetching relation fields of toOne relations
> ---------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Updated] (OPENJPA-2296) N+1 select problems when eager
fetching OneToOne and ManyToOne fields
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Vermeulen updated OPENJPA-2296:
-------------------------------
Description:
EDIT:
- the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
- The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue. (Somehow my fields are in the list of eager relations in OpenJPA's trace, but OpenJPA still uses a "load field" for them.)
We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
Suppose we have entities Company 1..* Employee 1..* Project
According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
....
41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
....
In the first (efficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
In the second (inefficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
was:
EDIT:
- the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
- The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue.
We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
Suppose we have entities Company 1..* Employee 1..* Project
According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
....
41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
....
In the first (efficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
In the second (inefficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
> N+1 select problems when eager fetching OneToOne and ManyToOne fields
> ---------------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> EDIT:
> - the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
> - The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue. (Somehow my fields are in the list of eager relations in OpenJPA's trace, but OpenJPA still uses a "load field" for them.)
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Comment Edited] (OPENJPA-2296) N+1 select in eager fetching
relation fields of toOne relations
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13493917#comment-13493917 ]
Vermeulen edited comment on OPENJPA-2296 at 11/9/12 11:57 AM:
--------------------------------------------------------------
Moving up the call stack I see that the eager select type used for fetching the field entities.Company.employee is indeeds set to join
by RelationFieldStrategy.selectEagerJoin. I think it is logical that a toOne uses a join instead of parallel select. However somehow further on this causes JDBCStoreManager.select to not consider parallel mode anymore for any of the relation fields of Employee. This can be seen where it calls createEagerSelects using the line
eager = Math.min(eager, fetch.getEagerFetchMode())
which results in JOIN, not parallel. Somehow the code in JDBCStoreManager.createEagerSelects that considers whether or not a JOIN strategy can be used also rejects this later resulting in the N+1 select problem.
I suspect that this problem may have been introduced when someone tried to prevent other bugs. The RelationFieldStrategy.selectEagerJoin that restricts the eager select mode to join has this comment (already in oldest version of svn):
// limit the eager mode to single on recursive eager fetching b/c
// at this point the select has been modified and an attempt to
// clone it for a to-many eager select can result in a clone that
// produces invalid SQL
I am now giving up my debugging because I really have insufficient knowledge of OpenJPA to know how to proceed from this without introducing new bugs. But I think I have provided more than enough information for an active OpenJPA committer to proceed from here to solve the problem for which I would be very grateful.
was (Author: slowstrider):
Moving up the call stack I see that the eager select type used for fetching the field entities.Company.employee is indeeds set to join
by RelationFieldStrategy.selectEagerJoin. I think it is logical that a toOne uses a join instead of parallel select. However somehow further on this causes JDBCStoreManager.select to not consider parallel mode anymore for any of the relation fields of Employee. This can be seen where it calls createEagerSelects using the line
eager = Math.min(eager, fetch.getEagerFetchMode())
which results in JOIN, not parallel. Somehow this also doesn't result in an efficient SQL with join but gives the N+1 select.
I suspect that this problem may have been introduced when someone tried to prevent other bugs. The RelationFieldStrategy.selectEagerJoin that restricts the eager select mode to join has this comment (already in oldest version of svn):
// limit the eager mode to single on recursive eager fetching b/c
// at this point the select has been modified and an attempt to
// clone it for a to-many eager select can result in a clone that
// produces invalid SQL
I am now giving up my debugging because I really have insufficient knowledge of OpenJPA to know how to proceed from this without introducing new bugs. But I think I have provided more than enough information for an active OpenJPA committer to proceed from here to solve the problem for which I would be very grateful.
> N+1 select in eager fetching relation fields of toOne relations
> ---------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
>
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Updated] (OPENJPA-2296) N+1 select in eager fetching
relation fields of toOne relations
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Vermeulen updated OPENJPA-2296:
-------------------------------
Description:
EDIT: the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
Suppose we have entities Company 1..* Employee 1..* Project
According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
....
41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
....
In the first (efficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
In the second (inefficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
was:
We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
Suppose we have entities Company 1..* Employee 1..* Project
According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
....
41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
....
In the first (efficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
In the second (inefficient) case OpenJPA logs
openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
> N+1 select in eager fetching relation fields of toOne relations
> ---------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> EDIT: the N+1 select problem also always occurs when eagerly fetching a ManyToOne field!
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (OPENJPA-2296) N+1 select in eager fetching
relation fields of toOne relations
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13493881#comment-13493881 ]
Vermeulen commented on OPENJPA-2296:
------------------------------------
I found a proof of concept that it IS easily possible to solve this problem!
I have put a breakpoint on JDBCStoreManager.createEagerSelects at the comment "finally, try parallel". (line 1242 in 2.2.0)
When it considers the field Employee.projects (variable fms[i].toString()), somehow the variable "eager" is always set to EagerFetchModes.JOIN (=1) and then skipped. When I change the value of "eager" to EagerFetchModes.EAGER_PARALLEL (=2) using the debugger (have to do this twice), the problem goes away! I then get the exact expected where the tables are joined together:
28154 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
37302 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employee]
37302 testPU TRACE [main] openjpa.jdbc.SQL - <t 14095358, conn 20099128> executing prepstmnt 15828664 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
37306 testPU TRACE [main] openjpa.jdbc.SQL - <t 14095358, conn 20099128> [4 ms] spent
37306 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employee]
37306 testPU TRACE [main] openjpa.jdbc.SQL - <t 14095358, conn 20099128> executing prepstmnt 12827479 SELECT t1.id, t2.id, t2.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
37312 testPU TRACE [main] openjpa.jdbc.SQL - <t 14095358, conn 20099128> [6 ms] spent
37553 testPU TRACE [main] openjpa.jdbc.JDBC - <t 14095358, conn 0> [0 ms] close
> N+1 select in eager fetching relation fields of toOne relations
> ---------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
>
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (OPENJPA-2296) N+1 select problems when eager
fetching OneToOne and ManyToOne fields
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13500937#comment-13500937 ]
Vermeulen commented on OPENJPA-2296:
------------------------------------
- For the bidirectional ManyBToOneA, using @EagerFetchMode(FetchMode.PARALLEL) on the ManyToOne reference to A solves the N+1 problem and uses 3 queries. However this does not work in the Company - Project - Employee example.
- Hibernate has an @Fetch(FetchMode.SUBSELECT) which is similar and solves the problem. It also has a @BatchSize annotation that uses one query to load a field for multiple entity instances by their oid. This would also be a very good solution to fix the N+1 select problem. This would mean that the employee.projects fields could be loaded for e.g. 50 employees with one query. Are there any plans of implementing such a feature?
> N+1 select problems when eager fetching OneToOne and ManyToOne fields
> ---------------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> EDIT:
> - an N+1 select problem also always occurs when eagerly fetching a ManyToOne field that is bidirectional (see TestManyOneEagerSQL)
> - The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue. (Somehow my fields are in the list of eager relations in OpenJPA's trace, but OpenJPA still uses a "load field" for them.)
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (OPENJPA-2296) N+1 select problems when eager
fetching OneToOne and ManyToOne fields
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13497971#comment-13497971 ]
Vermeulen commented on OPENJPA-2296:
------------------------------------
I also tested the simple Order - Customer example with Hibernate and EclipseLink. Both of them generate N+1 selects for the unidirectional ManyToOne case, So OpenJPA performs better here. Both of them can be optimized to use one query when adding "JOIN FETCH o.customer". Both of them always use N+1 select in case the relation is bidirectional and eager in both directions.
I don't know what info I am missing here. A bidirectional Order and Customer example seems to be a quite common example, So why does this alread break? Shouldn't it be the responsibility of the JPA provider to optimize eager fetching? Is this such complex matter that this is technically very hard or impossible to do? Or is this simply low priority for JPA providers?
> N+1 select problems when eager fetching OneToOne and ManyToOne fields
> ---------------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
> Attachments: OPENJPA-2296-tests.zip
>
>
> EDIT:
> - an N+1 select problem also always occurs when eagerly fetching a ManyToOne field that is bidirectional (see TestManyOneEagerSQL)
> - The patch of "RelationFieldStrategy.selectEagerJoin" I suggested works for the unit tests but does not work in my real application so that may be a different N+1 select issue. (Somehow my fields are in the list of eager relations in OpenJPA's trace, but OpenJPA still uses a "load field" for them.)
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (OPENJPA-2296) N+1 select in eager fetching
relation fields of toOne relations
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13493917#comment-13493917 ]
Vermeulen commented on OPENJPA-2296:
------------------------------------
Moving up the call stack I see that the eager select type used for fetching the field entities.Company.employee is indeeds set to join
by RelationFieldStrategy.selectEagerJoin. I think it is logical that a toOne uses a join instead of parallel select. However somehow further on this causes JDBCStoreManager.select to not consider parallel mode anymore for any of the relation fields of Employee. This can be seen where it calls createEagerSelects using the line
eager = Math.min(eager, fetch.getEagerFetchMode())
which results in JOIN, not parallel. Somehow this also doesn't result in an efficient SQL with join but gives the N+1 select.
I suspect that this problem may have been introduced when someone fixed another bug. The RelationFieldStrategy.selectEagerJoin that restricts the eager select mode to join has this comment:
// limit the eager mode to single on recursive eager fetching b/c
// at this point the select has been modified and an attempt to
// clone it for a to-many eager select can result in a clone that
// produces invalid SQL
I am now giving up my debugging because I really have insufficient knowledge of OpenJPA to know how to proceed from this without introducing new bugs. But I think I have provided more than enough information for an active OpenJPA committer to proceed from here to solve the problem for which I would be very grateful.
> N+1 select in eager fetching relation fields of toOne relations
> ---------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
>
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Commented] (OPENJPA-2296) N+1 select in eager fetching
relation fields of toOne relations
Posted by "Vermeulen (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/OPENJPA-2296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13493853#comment-13493853 ]
Vermeulen commented on OPENJPA-2296:
------------------------------------
Note that explicitly doing a left join fetch query or setting fetchplan recursion depth does not help.
I am currently using the Eclipse debugger to localize the problem.
I suspect that the bug is inside JDBCStoreManager.createEagerSelects(). This is the method that determines the list of Eager relations that is shown in the trace. When Project - Employee is toOne it does consider Employee.projects but somehow skips it. When it is toMany, the relation is not skipped and it is added as eager.
I think at a high level in the EagerResultList we then see the consequence: the project relations are not yet fetched inside the "main query" of ResultObjectProvider.open(). After this, the while loop of EagerResultList adds entities and each call to load an Employee entity has to do an actual database load instead of reusing the entities that should be present in the context.
> N+1 select in eager fetching relation fields of toOne relations
> ---------------------------------------------------------------
>
> Key: OPENJPA-2296
> URL: https://issues.apache.org/jira/browse/OPENJPA-2296
> Project: OpenJPA
> Issue Type: Bug
> Components: jdbc, kernel, performance
> Affects Versions: 2.2.1
> Reporter: Vermeulen
> Priority: Critical
>
> We have very serious performance problems in fetching our JPA entities caused by N+1 select problems. I suspect that these are caused by a small bug in OpenJPA's eager fetching implementation that should not be too hard to fix. This is especially bad in our relatively complex reservation entity where we need to eagerly fetch customer, contacts, orderlines, products etc. It takes over 3 seconds to fetch a single reservation from a local db. The problem seems to occur at multiple places in this object graph. The cause of the problem is probably the following issue where eager fetching of relations of toOne relations use neither a parallel or join select strategy but uses separate "load field"s of EACH field of EACH toOne relation in the object graph. I am not the only one having this issue, see also mailing list http://openjpa.208410.n2.nabble.com/Fetchgroups-recursion-problem-td3874382.html#a7581598
> Suppose we have entities Company 1..* Employee 1..* Project
> According to Chapter 8. Eager Fetching of the manual: "Continuing our example, if the Employee class had a list of Projects in one of the fetch groups being loaded, OpenJPA would execute a single additional select in parallel to load the projects of all employees of the matching companies."
> This is indeed what happens when both relations are eager (or are marked lazy but are in the fetchplan). The number of queries needed to fetch a Company does not depend on the number of employees or projects:
> 8913 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 19885 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 19889 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 20965449 SELECT t0.id, t0.name FROM Company t0
> 19891 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [2 ms] spent
> 20237 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 20237 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 21924553 SELECT t0.id, t1.id, t1.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID ORDER BY t0.id ASC
> 20248 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [10 ms] spent
> 21308 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
> 21309 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> executing prepstmnt 13123665 SELECT DISTINCT t1.id, t2.id, t2.name FROM Company t0 INNER JOIN Employee t1 ON t0.id = t1.COMPANY_ID INNER JOIN Project t2 ON t1.id = t2.EMPLOYEE_ID ORDER BY t1.id ASC
> 21376 testPU TRACE [main] openjpa.jdbc.SQL - <t 12833564, conn 5535786> [67 ms] spent
> 22247 testPU TRACE [main] openjpa.jdbc.JDBC - <t 12833564, conn 0> [0 ms] close
> However when the relation between Company and Employee is replaced with a OneToOne or ManyToOne relation, this efficient eager fetching fails and OpenJPA resorts to single object loads for the projects field of each Employee:
> ....
> 41580 testPU TRACE [main] openjpa.Query - Executing query: SELECT z FROM Company z
> 49121 testPU TRACE [main] openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> 49121 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 17563180 SELECT t0.id, t1.id, t1.name, t0.name FROM Company t0 LEFT OUTER JOIN Employee t1 ON t0.id = t1.COMPANY_ID
> 49142 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [21 ms] spent
> 61282 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=51 class entities.Employee
> 62593 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 27638389 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> 62594 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> [1 ms] spent
> 64554 testPU TRACE [main] openjpa.jdbc.SQLDiag - load field: 'projects' for oid=52 class entities.Employee
> 67645 testPU TRACE [main] openjpa.jdbc.SQL - <t 22418487, conn 10229202> executing prepstmnt 18914646 SELECT t0.id, t0.name FROM Project t0 WHERE t0.EMPLOYEE_ID = ? [params=?]
> ....
> In the first (efficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Employee.projects, entities.Company.employees]
>
> In the second (inefficient) case OpenJPA logs
> openjpa.jdbc.SQLDiag - Eager relations: [entities.Company.employee]
> This issue may be related to https://issues.apache.org/jira/browse/OPENJPA-1920 which also uses single "load field"s.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira