Hibernate 5.4.22 loads a many to one lazy relationship

Description

We recently upgraded from hibernate version 5.3.10 to 5.4.22 and after several rounds of load testing we noticed performance degradation in some of our APIs. After investigating the issue, we noticed that many to one lazy loaded relationships are being loaded in hibernate 5.4.22 whereas they were not in 5.3.10. We then proceeded to downgrade to 5.3.18, 5.3.17 and 5.3.16 but the behavior was still the same as 5.4.22. Finally when we downgraded to 5.3.15 then we noticed it behaved like 5.3.10 and the many to one lazy loaded relationship wasn't loaded. Here is a sample of the relationship from our code:

And here is the output of hibernate logging for different releases we tried:

Hibernate 5.4.22 output
2020-11-02 21:32:31,999 DEBUG [wm-exec-16] org.hibernate.engine.internal.TwoPhaseLoad - Resolving attributes for [com.mycompany.Session#component[partition,uuid]{partition=202011, uuid=429639935898461622951168262500944579}]
2020-11-02 21:32:32,000 DEBUG [wm-exec-16] org.hibernate.engine.internal.TwoPhaseLoad - Attribute (`product`) - enhanced for lazy-loading? - false
2020-11-02 21:32:32,000 DEBUG [wm-exec-16] org.hibernate.persister.entity.NamedQueryLoader - Ignoring lock-options passed to named query loader
2020-11-02 21:32:32,000 DEBUG [wm-exec-16] org.hibernate.persister.entity.NamedQueryLoader - Loading entity: com.mycompany.Product using named query: findProductById

Hibernate 5.3.16 – 5.3.18 output
2020-11-02 22:32:45,081 DEBUG [wm-exec-13] org.hibernate.engine.internal.TwoPhaseLoad - Resolving associations for [com.mycompany.Session#component[partition,uuid]{partition=202011, uuid=429639935898461622951168262500944579}]
2020-11-02 22:32:45,081 DEBUG [wm-exec-13] org.hibernate.persister.entity.NamedQueryLoader - Ignoring lock-options passed to named query loader
2020-11-02 22:32:45,081 DEBUG [wm-exec-13] org.hibernate.persister.entity.NamedQueryLoader - Loading entity: com.mycompany.Product using named query: findProductById

Hibernate 5.3.15 output
2020-11-02 23:22:29,601 DEBUG [wm-exec-68] org.hibernate.engine.internal.TwoPhaseLoad - Resolving associations for [com.mycompany.Session#component[partition,uuid]{partition=202011, uuid=429639935898461622951168262500944579}]
2020-11-02 23:22:29,601 DEBUG [wm-exec-68] org.hibernate.engine.internal.TwoPhaseLoad - Done materializing entity [com.mycompany.Session#component[partition,uuid]{partition=202011, uuid=429639935898461622951168262500944579}]

Attachments

Linked issues

caused by

HHH-13891

ProxyFactory should not be built if any ID or property getter/setter methods are final

Activity

Show:

Christian Beikov November 12, 2020 at 9:25 AM

As mentioned in and as you can see here: this is the intended behavior as a proxy can’t function properly when final methods are invovled.

Christian Beikov November 7, 2020 at 10:45 AM

Thanks for the test case. I’ll take a deeper look when I find the time. Glad you found a workaround/fix in the meantime!

Edwin Avedian November 6, 2020 at 11:21 PM

In the attached test project, the ‘Dorm’ entity has the ‘final’ method.

Edwin Avedian November 6, 2020 at 9:36 PM

We will remove the ‘final’ from our methods to fix this issue but wanted to understand the scope of the change in hibernate 5.3.16 that is causing the difference in behavior.

Edwin Avedian November 6, 2020 at 9:34 PM
Edited

Christian, I am sorry for the delay but I am able to reproduce the problem in an isolated project and I actually found the root cause of the issue. We had an entity with a ‘public final’ method and because of this final method hibernate 5.3.16 issues a an extra query against the DB but in 5.3.15 it isn’t.

Please unzip the attached and from the command line please run

mvn test -Dtest=com.jpatest.Tests#test

and then change the hibernte-core reference in pom.xml to 5.3.15 and 5.3.16 and see the difference in the output. In 5.3.16 two queries are generated whereas in 5.3.15 only one query is generated.