http://coldfusion.com logo
Join Slack
Powered by
I've got a client server running Lucee `5.4.2.17` ...
# lucee
b
I've got a client server running Lucee 
5.4.2.17
where I'm seeing a fair amount of stack traces on the server having exactly the same spot they are at (in thread). It's nothing particularly interesting, however • it's classloading which makes it a pain to troubleshoot, always in the process of loading the page source for a CFC that's being instantiated • It's always inside the 
PageSourceImpl.loadArchive()
method even though the CFC in question is not part of a Lucee archive • I'm unclear why this class loading always seem to be slow, and under a lot of load, it's causing very serious locks due to synchronized methods in the 
PageSourceImpl
class where one thread doing the class loading will block ALL OTHER THREADS waiting to create an instance of the same CFC. See this ticket • I don't even understand why Lucee is doing the class loading at all! This production server should have class cached in the page pool, which I've hacked to have a max of 10,000 and I'm monitoring the size so I know for 100% certainty that the page polls aren't full or even close. • This week we had to remove 2 CFCs from the session scope which is stored in Redis and deserialized each request as the CFC template class loading on the same 2 CFCs every request was just locking up the entire server, especially when CPU usage on their swarm nodes was high and the code inside the synchronized methods slowed down even more. Check out the partial stack trace in the thread and let me know if you've ever seen this before.
Copy code
org.apache.felix.framework.BundleWiringImpl.findClassOrResourceByDelegation(BundleWiringImpl.java:1591)
org.apache.felix.framework.BundleWiringImpl.access$300(BundleWiringImpl.java:79)
org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.loadClass(BundleWiringImpl.java:1976)
java.lang.ClassLoader.loadClass(Unknown Source)
org.apache.felix.framework.Felix.loadBundleClass(Felix.java:2116)
org.apache.felix.framework.BundleImpl.loadClass(BundleImpl.java:986)
lucee.runtime.MappingImpl.getArchiveClass(MappingImpl.java:192)
lucee.runtime.PageSourceImpl.loadArchive(PageSourceImpl.java:282)
lucee.runtime.PageSourceImpl.loadPageThrowTemplateException(PageSourceImpl.java:242)
 - locked <0x2ea3527c> (a lucee.runtime.PageSourceImpl)
lucee.runtime.component.ComponentLoader._search(ComponentLoader.java:343)
lucee.runtime.component.ComponentLoader._search(ComponentLoader.java:188)
lucee.runtime.component.ComponentLoader.searchComponent(ComponentLoader.java:87)
lucee.runtime.ComponentImpl.init(ComponentImpl.java:381)
models.agency.office.agent_cfc$cf.initComponent(/client/models/Agency/Office/Agent.cfc)
☝️ Notice the lock on the 
PageSourceImpl
instance which block all other threads on the server from being able to create an instance of this same CFC until this thread is done with the classloading its doing, even though the class should totally be cached in memory.
Also note the stack always looks exactly like this, where the logic is inside the 
PageSourceImpl.loadArchive()
method even though this CFC does not live in an archive at all, but a normal CF mapping.
The only registered mappings that point to an archive outside of the core Lucee ones is this
Copy code
/cfspreadsheet/	/usr/local/lib/serverHome/WEB-INF/lucee-server/context/archives/cfc/cfspreadsheet/cfc-archive-cfspreadsheet.lar
z
A repo would be good, the clue with redis is interesting as deserializimg objects from an extension needs to be able to load classes from the Lucee core as it can't access objects via OSGi directly
b
@zackster When profiling the server, I see other normal http threads just creating the CFCs inside CF code that also show the same slow classloading, so it's nothing specific to session deserialization. Having CFCs in session, simply made that logic run all the more often. And the "classes" are simply CFC instances that Lucee JIT compiled, so no OSGI is involved at all.
z
are they using component mappings via application.cfc ?
b
Yes
@zackster Man, my client's server is just getting pummeled this morning by this page source contention. Here's an interesting thing I noticed-- this app has a lot of old school <CFInvoke> calls. I'm starting at a stack trace that FusionReactor just E-mailed me and all of the hung threads seem to be creating CFCs via invoke. Now, that could be a skewed sample since nearly ALL the CFC calls in this app use cfinvoke, but do you think cfinvoke somehow bypasses the page pool cache?
Here's an example
Copy code
lucee.runtime.PageSourceImpl.loadPageThrowTemplateException(PageSourceImpl.java:233)
- waiting on <0x10acfb98> (a lucee.runtime.PageSourceImpl held by thread 13849, XNIO-1 task-28)
lucee.runtime.component.ComponentLoader._search(ComponentLoader.java:343)
lucee.runtime.component.ComponentLoader._search(ComponentLoader.java:188)
lucee.runtime.component.ComponentLoader.searchComponent(ComponentLoader.java:82)
lucee.runtime.PageContextImpl.loadComponent(PageContextImpl.java:3280)
lucee.runtime.tag.Invoke.doComponent(Invoke.java:206)
lucee.runtime.tag.Invoke.doEndTag(Invoke.java:186)
models.client_cfc$cf.udfCall7(/client/models/client.cfc:2172)
models.client_cfc$cf.udfCall(/client/models/client.cfc)
And the code in question is
Copy code
<cfinvoke scope="Internal" component="client.models.Agency.Office.Agent" method="AgentFind" returnvariable="GetOfficeID">
				<cfinvokeargument name="param" value="">
				<cfinvokeargument name="param2" value="">
				<cfinvokeargument name="param3" value="">
			</cfinvoke>
I still don't understand why Lucee needs to search for the same dang CFC every time, and why two threads can't search for the same component at the same time.
Again, here's the thread holding the whole server hostage (at the moment the stack trace was taken)
Copy code
org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.loadClass(BundleWiringImpl.java:1993)
java.lang.ClassLoader.loadClass(Unknown Source)
org.apache.felix.framework.Felix.loadBundleClass(Felix.java:2116)
org.apache.felix.framework.BundleImpl.loadClass(BundleImpl.java:986)
lucee.runtime.MappingImpl.getArchiveClass(MappingImpl.java:192)
lucee.runtime.PageSourceImpl.loadArchive(PageSourceImpl.java:282)
lucee.runtime.PageSourceImpl.loadPageThrowTemplateException(PageSourceImpl.java:242)
- locked <0x10acfb98> (a lucee.runtime.PageSourceImpl)
lucee.runtime.component.ComponentLoader._search(ComponentLoader.java:343)
lucee.runtime.component.ComponentLoader._search(ComponentLoader.java:188)
lucee.runtime.component.ComponentLoader.searchComponent(ComponentLoader.java:82)
lucee.runtime.PageContextImpl.loadComponent(PageContextImpl.java:3280)
lucee.runtime.tag.Invoke.doComponent(Invoke.java:206)
lucee.runtime.tag.Invoke.doEndTag(Invoke.java:186)
models.client$cf.udfCall7(/client/models/client.cfc:2172)
models.client$cf.udfCall(/client/models/client.cfc)
You can see it's actually the same exact line of CF code. Lucee has effectively single-threaded parts of my client's app 😕
4 Views
Open in Slack
PreviousNext
Powered by