Lazy loading - spends 50% of time in Spring internal code

[alexbudarov]

Environment

Jmix version: 2.3.4, 2.4.2.

Bug Description

Lazy loading mechanism spends significant portion of time inside of Spring internals, not in the JPA / JDBC / network I/O code.

Steps To Reproduce

• Load and lazily traverse an entity graph:
  20 Owners -> 20 Pets each -> 20 Visits each

For me: it took 9467 ms.

• As the test starts, quickly connect with Visualvm to the gradle tests process, and take CPU sampling during this traversion.

Current Behavior

CPU sampling report shows that around 50% of sampled time is spent inside of Spring classes.
See screenshot.

• walkThrough method -- takes 9499 ms
• 2 invocations of ContextAnnotationAutowireCandidateReoslver$1.getTarget - take 3499 + 804 = 4303 ms.
• DefaultListableBeanFactory.getBean - takes 300 ms more.

In total it is 4603 ms = 48% of the total method execution.

It looks inefficient to spend so much CPU time there.
And it is a real CPU activity, not sleeping waiting for the network I/O.

Expected Behavior

Majority of time should be spent in awaiting for database response.

Sample Project

Modified petclinic sample:

jmix-petclinic.zip

Launch test class: io.jmix.petclinic.LazyLoadingPerformanceTest