createObject reloads all OSGI bundles if javaSettings are configured

Description

None

Environment

This is a performance regression in 5.3.9.x. (I’m having trouble pinning down the exact version.)

Basically, a createObject( "java", "java.internal.class" ) can be extremely slow when run at scale. When profiling via Fusion Reactor, it appears this is because Lucee is loading all OSGI bundles every time - i.e. the OSGI lookup is never cached.

This is similar to https://luceeserver.atlassian.net/browse/LDEV-2952, but it appears to be a different cause.

Attachments

09 Sept 2022, 05:06 pm
01 Jul 2022, 05:30 pm
01 Jul 2022, 05:30 pm

Linked issues

relates to

LDEV-2952

Classloading from OSGI bundles is 27,000 times slower

Activity

Show:

dan.switzer@givainc.com 9 December 2022 at 17:29

First, thanks for this fix. It looks like it’s going to resolve a race condition we’ve been seeing under load where threads were hang.

I’ve been trying to see if I could recreate the race condition and finally came up with something that duplicates the behavior. It does not mirror our production code directly, but it results in similar stack traces where the threads end up getting stuck in a lock trying to load a class.

If you run the attached code under a web stress tool (like jMeter) and just send a large amount of requests at it, you’ll see that the threads quickly get stuck in a race condition. If you remove the {{this.javaSettings}} from the {{Application.cfc}} and restart Lucee, it will run fine. I chose to load the Lucee server bundle, only because I knew it would exist in the environment. It doesn’t matter what JARs you load, you just need to load some.

When I test under 5.3.10.97 the problem is resolved (it’s broken under 5.3.9.141).

Since I can’t seem to attach a zip file, here is the code you need:

Application.cfc

component {
	this.name               = "lucee_hang_request";
	this.sessionManagement  = false;
	this.applicationTimeout = createTimeSpan(0, 0, 5, 0);

	/*
		It's the use of configuring the application to load classes from a specific
		location that seems to cause the issues. It does not matter which path you
		load some Java classes from, but as long as there are some JAR files in the
		path, then in Lucee 5.3.9.141 under load, trying to load any Java class from
		createObject() can result in race condition which prevents Lucee from being
		able to load the class.

		If you commented this line out, then the race condition no longer occurs.
	*/
	this.javaSettings = {
		  loadPaths                = [expandPath("{lucee-server}../bundles/")]
		, loadColdFusionClassPath  = false
		, reloadOnChange           = true
		, watchInterval            = 5
	};

	public boolean function onRequestStart(){
		return true;
	}

}

lucee_hang_request_20221205.cfm

<cfscript>
	/*
		When this template is under load, it will lead to race
		conditions under Lucee which will prevent the createObject()
		call from being able to instantiate new instances due
		to a race condition in the locking mechanism.

		Having the createObject() inside a function seemed to make
		the race condition behavior more consistent.
	*/
	function x(){
		return createObject("java", "java.util.TimeZone");
	}

	writeOutput(getTickCount() & "<br />");

	threadNames = [];
	for( idx=0; idx < 50; idx++ ){
		tName = "t_hang_test_" & createUUID();

		/*
			While the production code running into the issue was not using
			threads, it was the only way I could reliably create the race
			condition.
		*/
		thread action="run" name="#tName#" {
			x();
		}

		threadNames.append(tName);
	}

	/*
		We wait for the threads to finish, so we can better see the
		parent threads being affected by the race condition.
	*/
	thread action="join" name="#threadNames.toList(',')#";
</cfscript>

Michael Born @ Ortus 20 September 2022 at 16:06

@Former user If this ticket was fixed, then I’m going to presume the assignee found the root cause. 😁

Former user 14 September 2022 at 09:45

@Michael Born @ Ortus : @Former user your issue seems completely unrelated to this ticket.

May be so. Which gets me curious to know if anyone has found the root cause in both cases.

My thinking is that, in both cases, the degradation in performance is due to locking or singlethreadedness during class/component loading. Just a preliminary thought.

Michael Born @ Ortus 13 September 2022 at 16:02

FWIW, I never claimed this issue only occurs on internal Java classes. I’m sure it also occurs/occurred on java classes in OSGI bundles or jars in the application this.javasettings as well. (And I’m hoping the fix accounts for that as well?)

@Former user your issue seems completely unrelated to this ticket.

Former user 13 September 2022 at 08:23

In fact, we’ve discovered a similar performance-degrading issue involving Lucee’s Built-In-Functions (BIFs).

Fixed

Details
Assignee
Pothys - MitrahSoft
Reporter
Michael Born @ Ortus
Priority
New
Labels
javaosgiperformanceregression
Fix versions
5.3.10.26
6.0.0.189
5.3.9.148
New Issue warning screen
Before you create a new Issue, please post to the mailing list first https://dev.lucee.org
Once the issue has been verified, one of the Lucee team will ask you to file an issue

Created 1 July 2022 at 17:30

Updated 9 December 2022 at 17:29

Resolved 29 August 2022 at 13:43