Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Speedup of Hibernate ORM's processing of very large models #40160

Closed
wants to merge 1 commit into from

Conversation

Sanne
Copy link
Member

@Sanne Sanne commented Apr 19, 2024

These two commits implement two different optimisations which will enhance the live-reload experience for non-trivial entity models.

A reference "benchmark" we have ( https://github.com/topicusonderwijs/tribe-krd-quarkus ) improves with this by about 40%.
I'm hoping for much stronger improvements, but the other problems I see need to be addressed in Hibernate ORM - some of which are being addressed in ORM 7.

So this doesn't entirely solve the problem yet, but it's a solid milestone in the right direction.

My particular machine has several cores and after this patch is applied the next bottleneck happens to become contention on some internal caches we use during enhancement - my "40% improvement" is measured after taking out that contention point as well, so I'm not sure how this patch by itself might translate to another system.

cc/ @dashorst @yrodiere

@quarkus-bot quarkus-bot bot added area/hibernate-orm Hibernate ORM area/persistence OBSOLETE, DO NOT USE labels Apr 19, 2024
Copy link

quarkus-bot bot commented Apr 19, 2024

/cc @gsmet (hibernate-orm), @yrodiere (hibernate-orm)

}
};
this.enhancer = PROVIDER.getEnhancer(enhancementContext);
this.enhancer = enhancer;
Copy link
Member Author

@Sanne Sanne Apr 19, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is the crux of the patch: reuse a single Enhancer instace for all processed entities rather than creating a new one each time.

Creating an enhancer is extremely taxing, especially on the classloader as ByteBuddy needs to load a gazillion of bytecode streams to generate its templates - we designed it intentionally so to preapre all the possible templates in advance to then process multiple entities efficiently.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does this mean the enhancer is shared across multiple persistence units? Is that safe?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It should be yes - the entity enhancement does not depend on the PU.

Also this way of processing things is more similar to how ORM's build utilities would do it: the Enhancer was meant to be reused on a batch of files.

@dashorst
Copy link

Really awesome to see the tribe-krd-quarkus repo put to good use. (I am personally trying to work out if I can build a minimal HTMX type of web application on top of the domain model, to make it more compelling, possibly trying to craft some real business like queries).

Keep on going!

This comment has been minimized.

@Sanne
Copy link
Member Author

Sanne commented Apr 20, 2024

re-pushing as I had a small mistake in the classloader optimisation - nice to see CI had caught it!

This comment has been minimized.

Copy link
Member

@yrodiere yrodiere left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just one comment... also, tests don't pass :]

}
};
this.enhancer = PROVIDER.getEnhancer(enhancementContext);
this.enhancer = enhancer;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does this mean the enhancer is shared across multiple persistence units? Is that safe?

@Sanne Sanne force-pushed the ORMClassloadOpt branch 2 times, most recently from 7b6adc9 to a7c0550 Compare April 22, 2024 10:18
@Sanne
Copy link
Member Author

Sanne commented Apr 22, 2024

I've re-pushed it to try figure out what's going on with the test: stuff works fine locally.

There were two separate commits related to two different improvements; I've removed the less interesting one to try narrow it down.

This comment has been minimized.

@Sanne Sanne force-pushed the ORMClassloadOpt branch from a7c0550 to 7f6e960 Compare April 23, 2024 22:10
Copy link

quarkus-bot bot commented Apr 23, 2024

Status for workflow Quarkus CI

This is the status report for running Quarkus CI on commit 7f6e960.

Failing Jobs

Status Name Step Failures Logs Raw logs Build scan
JVM Tests - JDK 17 Build Failures Logs Raw logs 🔍
JVM Tests - JDK 21 Build Failures Logs Raw logs 🔍
JVM Tests - JDK 17 Windows Build Failures Logs Raw logs 🔍

Full information is available in the Build summary check run.
You can consult the Develocity build scans.

Failures

⚙️ JVM Tests - JDK 17 #

- Failing: extensions/hibernate-orm/deployment 
! Skipped: extensions/flyway/deployment extensions/hibernate-envers/deployment extensions/hibernate-reactive/deployment and 86 more

📦 extensions/hibernate-orm/deployment

io.quarkus.hibernate.orm.applicationfieldaccess.PublicFieldAccessAssociationsTest.testFieldAccess line 60 - History - More details - Source on GitHub

org.opentest4j.AssertionFailedError: 

expected: io.quarkus.hibernate.orm.applicationfieldaccess.PublicFieldAccessAssociationsTest$ContainedEntity@3ad834a9
 but was: null
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)

⚙️ JVM Tests - JDK 21 #

- Failing: extensions/panache/hibernate-reactive-rest-data-panache/deployment 

📦 extensions/panache/hibernate-reactive-rest-data-panache/deployment

io.quarkus.hibernate.reactive.rest.data.panache.deployment.repository.PanacheRepositoryResourcePutMethodTest.shouldUpdateComplexObject - History - More details - Source on GitHub

java.lang.AssertionError: 
1 expectation failed.
JSON path name doesn't match.
Expected: is "updated collection"
  Actual: empty collection

	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:502)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:486)

⚙️ JVM Tests - JDK 17 Windows #

- Failing: extensions/panache/hibernate-orm-rest-data-panache/deployment 
! Skipped: integration-tests/hibernate-orm-rest-data-panache 

📦 extensions/panache/hibernate-orm-rest-data-panache/deployment

io.quarkus.hibernate.orm.rest.data.panache.deployment.entity.PanacheEntityResourcePutMethodTest.shouldUpdateSimpleObject - History - More details - Source on GitHub

java.lang.AssertionError: 
1 expectation failed.
JSON path name doesn't match.
Expected: is "first-test"
  Actual: first

	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)

io.quarkus.hibernate.orm.rest.data.panache.deployment.repository.PanacheRepositoryResourcePutMethodTest.shouldUpdateSimpleObject - History - More details - Source on GitHub

java.lang.AssertionError: 
1 expectation failed.
JSON path name doesn't match.
Expected: is "first-test"
  Actual: first

	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)

Flaky tests - Develocity

⚙️ JVM Tests - JDK 21

📦 extensions/hibernate-orm/deployment

io.quarkus.hibernate.orm.applicationfieldaccess.PublicFieldAccessInheritanceTest.testFieldAccess - History

  • Expecting actual not to be null - java.lang.AssertionError
java.lang.AssertionError: 

Expecting actual not to be null
	at io.quarkus.hibernate.orm.applicationfieldaccess.PublicFieldAccessInheritanceTest$FieldAccessEnhancedDelegate$1.assertValue(PublicFieldAccessInheritanceTest.java:132)
	at io.quarkus.hibernate.orm.applicationfieldaccess.PublicFieldAccessInheritanceTest.doTestFieldAccess(PublicFieldAccessInheritanceTest.java:91)
	at io.quarkus.hibernate.orm.applicationfieldaccess.PublicFieldAccessInheritanceTest.testFieldAccess(PublicFieldAccessInheritanceTest.java:52)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	at io.quarkus.test.QuarkusUnitTest.runExtensionMethod(QuarkusUnitTest.java:500)

📦 extensions/hibernate-reactive/deployment

io.quarkus.hibernate.reactive.publicfields.PublicFieldAccessInheritanceTest.testFieldAccess(UniAsserter) - History

  • Expecting actual not to be null - java.lang.AssertionError
java.lang.AssertionError: 

Expecting actual not to be null
	at io.quarkus.hibernate.reactive.publicfields.PublicFieldAccessInheritanceTest$FieldAccessEnhancedDelegate$1.assertValue(PublicFieldAccessInheritanceTest.java:116)
	at io.quarkus.test.vertx.DefaultUniAsserter$1.accept(DefaultUniAsserter.java:38)
	at io.smallrye.context.impl.wrappers.SlowContextualConsumer.accept(SlowContextualConsumer.java:21)
	at io.smallrye.mutiny.operators.uni.UniOnItemConsume$UniOnItemComsumeProcessor.invokeEventHandler(UniOnItemConsume.java:77)
	at io.smallrye.mutiny.operators.uni.UniOnItemConsume$UniOnItemComsumeProcessor.onItem(UniOnItemConsume.java:42)
  • Expecting actual not to be null - java.lang.AssertionError
java.lang.AssertionError: 

Expecting actual not to be null
	at io.quarkus.hibernate.reactive.publicfields.PublicFieldAccessInheritanceTest$FieldAccessEnhancedDelegate$1.assertValue(PublicFieldAccessInheritanceTest.java:116)
	at io.quarkus.test.vertx.DefaultUniAsserter$1.accept(DefaultUniAsserter.java:38)
	at io.smallrye.context.impl.wrappers.SlowContextualConsumer.accept(SlowContextualConsumer.java:21)
	at io.smallrye.mutiny.operators.uni.UniOnItemConsume$UniOnItemComsumeProcessor.invokeEventHandler(UniOnItemConsume.java:77)
	at io.smallrye.mutiny.operators.uni.UniOnItemConsume$UniOnItemComsumeProcessor.onItem(UniOnItemConsume.java:42)

📦 extensions/panache/hibernate-orm-rest-data-panache/deployment

io.quarkus.hibernate.orm.rest.data.panache.deployment.entity.PanacheEntityResourcePutMethodTest.shouldUpdateSimpleObject - History

  • 1 expectation failed. JSON path name doesn't match. Expected: is "first-test" Actual: first - java.lang.AssertionError
java.lang.AssertionError: 
1 expectation failed.
JSON path name doesn't match.
Expected: is "first-test"
  Actual: first

	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:502)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:486)

📦 extensions/panache/hibernate-reactive-rest-data-panache/deployment

io.quarkus.hibernate.reactive.rest.data.panache.deployment.repository.PanacheRepositoryResourcePutMethodTest.shouldUpdateSimpleObject - History

  • 1 expectation failed. JSON path name doesn't match. Expected: is "first-test" Actual: first - java.lang.AssertionError
java.lang.AssertionError: 
1 expectation failed.
JSON path name doesn't match.
Expected: is "first-test"
  Actual: first

	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:502)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:486)
  • 1 expectation failed. JSON path name doesn't match. Expected: is "first-test" Actual: first - java.lang.AssertionError
java.lang.AssertionError: 
1 expectation failed.
JSON path name doesn't match.
Expected: is "first-test"
  Actual: first

	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:502)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:486)

⚙️ JVM Tests - JDK 17 Windows

📦 extensions/panache/hibernate-orm-rest-data-panache/deployment

io.quarkus.hibernate.orm.rest.data.panache.deployment.entity.PanacheEntityResourcePutMethodTest.shouldUpdateComplexObject - History

  • 1 expectation failed. JSON path name doesn't match. Expected: is "updated collection" Actual: empty collection - java.lang.AssertionError
java.lang.AssertionError: 
1 expectation failed.
JSON path name doesn't match.
Expected: is "updated collection"
  Actual: empty collection

	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)

@Sanne
Copy link
Member Author

Sanne commented Apr 26, 2024

Update: I've identified a tricky race condition in the underlying caches, trying to get it resolved in Hibernate ORM.

Technically it's not an Hibernate bug as it's normally not processing entity transformations in parallel... but it might explain this issue. I'm not sure if it's the culprit of the CI failure though as I could never replicate these failures locally, we'll have to try after that's solved.

@Sanne
Copy link
Member Author

Sanne commented Apr 26, 2024

This will be entirely different, might as well close the current PR.

@Sanne Sanne closed this Apr 26, 2024
@quarkus-bot quarkus-bot bot added the triage/invalid This doesn't seem right label Apr 26, 2024
@gsmet
Copy link
Member

gsmet commented Apr 27, 2024

@Sanne FWIW, CI is usually a lot more challenging for race conditions as it's a lot slower than our boxes. That might explain why you only see it failing on CI.

@Sanne
Copy link
Member Author

Sanne commented Apr 28, 2024

Right. I think I have a better understanding of where we had race conditions - TBH I don't think this patch introduced them, but since it's speeding up some processes it might make them revealed.

Followed up by #40329

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/hibernate-orm Hibernate ORM area/persistence OBSOLETE, DO NOT USE triage/flaky-test triage/invalid This doesn't seem right
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants