Classloading from OSGI bundles is 27,000 times slower

Description

While performance tuning an app that was converted from Lucee 4 to Lucee 5 in the last year I found a huge amount of slowness was caused by a large number of Java creations loaded from Hibernate, which comes from an OSGI bundle. (Up to 1,000 java creations per request) The classing loading itself is very slow and when I compared a simple test to Lucee 4, I found that loading Hibernate classes is 27,000 times slower on my machine compared to loading a class like java.lang.String.

If you run that code using the java.lang.String class, it completes in 3 ms. But if you run it using the Hibernate class, it takes over 80 seconds!

In Lucee 4.5, 10,000 creations of java.lang.String takes around 4 ms and 10,000 creations of a hibernate class take only 30 ms.

Here's the data in table form:

10,000 creations of java.lang.String
Lucee 4.5-- 4 milliseconds
Lucee 5.3.6-- 3 milliseconds

10,000 creations of any org.hibernate class
Lucee 4.5-- 30 milliseconds
Lucee 5.3.6-- 80+ seconds

Environment

None

Activity

Show:
Brad Wood
June 26, 2020, 6:06 PM

For anyone coming across this ticket, here is the workaround I put in the app I was working on which significantly increased performance again. Only do this if you are actually having performance issues. If you only create a small number of java objects, it's only around 10 ms apiece so not noticeable. You'll see performance issues if you're creating hundreds or thousands of Java objects. And this only seems to affect java classes loaded from OSGI bundles.

I replaced all instances of

with this:

And then I made sure this UDF was defined when the app started up

The way CFML works is when creating Java classes, the createObject() function doesn't actually return the Java class directly, but instead a java proxy which is capable of making calls to static methods on the class as well as instantiating fresh instances of the class when you call .init() OR you call any instance method (provided there is a zero-args constructor on the class).

The java proxy object can be re-used to create as many actual instances of a given class as you want like so:

This is basically what my workaround does-- it only creates a single instance of the java proxy and caches it in the Application scope for simplicity. Then that Java proxy is re-used in the place the createObject call to create instances without the class loading happening again.

Zac Spitzer
June 28, 2020, 10:36 AM

Do you see any page pool clearing logs?

Brad Wood
June 29, 2020, 2:23 PM

Not that I know of. Where would I look for that? This code is just loading Java classes so it doesn't seem like it should affect the page pool. According to the FusionReactor profiler, all the time is spent inside of loadClas() methods and my prevailing theory is that Lucee is looping over all the loaded bundles trying to find one that can provide the class and no caching of this lookup occurs. JDK classes would be found on the base classes loader and this found right away. And in Lucee 4.x, everything was in the base class loader.

Pothys - MitrahSoft
November 10, 2020, 10:18 AM

I've checked this ticket and confirmed the issue happened on lucee latest version 5.3.8.103-SNAPSHOT also. In lucee version 4.5.5.006 takes less time and the latest version takes more time for hibernate class as the reporter said above.

Assignee

Michael Offner

Reporter

Brad Wood

Priority

New

Labels

Fix versions

None
Configure