Performance Extension

hacking extensions
1

On Slack - I was asking about working out the current requests that were being processed to try and resolve a server issue where the Java / Tomcat process consumes 99% of CPU resources for long periods of time (greater than 10 minutes) - in the hope that I could try and track down a problematic CFM/CFC.

Thanks to @Brad_Wood and @Zackster, the Lucee Performance Analyzer was proposed as a possible solution.
(we do NOT currently have Fusion Reactor - I am trying!!!)

Anyway -

I followed the directions from the github page and installed it into the Web context and enabled the debug settings mentioned, there, also : on my local dev machine, for review / familiarisation.

When attempting to view the MEMORY report I get the following error;

failed to lazily initialize a collection of role: customer.datasources, no session or session was closed

error occurred in C:\Users\gavin\.CommandBox\server\592B6E067E8A62D47F295E727FEC9FD6-CentraCX\lucee-5.3.10.94-RC\WEB-INF\lucee-server\context\context\admin\plugin\PerformanceAnalyzer\memory.cfm:48
called by /lucee_plugin_directory/PerformanceAnalyzer/Action.cfc:47
called by /admin/plugin.cfm:78
called by /admin/web.cfm:492

Here is the stack Trace :

lucee.runtime.exp.NativeException: failed to lazily initialize a collection of role: customer.datasources, no session or session was closed 
at org.hibernate.collection.AbstractPersistentCollection.throwLazyInitializationException(AbstractPersistentCollection.java:383) 
at org.hibernate.collection.AbstractPersistentCollection.throwLazyInitializationExceptionIfNotConnected(AbstractPersistentCollection.java:375) 
at org.hibernate.collection.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:368) 
at org.hibernate.collection.AbstractPersistentCollection.read(AbstractPersistentCollection.java:111) 
at org.hibernate.collection.PersistentBag.listIterator(PersistentBag.java:469) 
at lucee.runtime.op.Duplicator.duplicateList(Duplicator.java:166) 
at lucee.runtime.op.Duplicator.duplicateList(Duplicator.java:162) 
at lucee.runtime.op.Duplicator.duplicate(Duplicator.java:134) 
at lucee.runtime.ComponentImpl.duplicateDataMember(ComponentImpl.java:340) 
at lucee.runtime.ComponentImpl._duplicate(ComponentImpl.java:258) 
at lucee.runtime.ComponentImpl._duplicate(ComponentImpl.java:244) 
at lucee.runtime.ComponentImpl._duplicate(ComponentImpl.java:244) 
at lucee.runtime.ComponentImpl.duplicate(ComponentImpl.java:212) 
at org.lucee.extension.orm.hibernate.tuplizer.proxy.ComponentProxy.duplicate(ComponentProxy.java:427) 
at lucee.runtime.op.Duplicator.duplicate(Duplicator.java:131) 
at lucee.runtime.ComponentImpl.duplicateDataMember(ComponentImpl.java:340) 
at lucee.runtime.ComponentImpl._duplicate(ComponentImpl.java:258) 
at lucee.runtime.ComponentImpl._duplicate(ComponentImpl.java:244) 
at lucee.runtime.ComponentImpl._duplicate(ComponentImpl.java:244) 
at lucee.runtime.ComponentImpl.duplicate(ComponentImpl.java:212) 
at lucee.runtime.op.Duplicator.duplicate(Duplicator.java:131) 
at lucee.runtime.type.StructImpl.copy(StructImpl.java:242) 
at lucee.runtime.type.StructImpl.duplicate(StructImpl.java:230) 
at lucee.runtime.op.Duplicator.duplicate(Duplicator.java:131) 
at lucee.runtime.type.StructImpl.copy(StructImpl.java:242) 
at lucee.runtime.type.StructImpl.duplicate(StructImpl.java:230) 
at lucee.runtime.op.Duplicator.duplicate(Duplicator.java:131) 
at lucee.runtime.type.StructImpl.copy(StructImpl.java:242) 
at lucee.runtime.type.StructImpl.duplicate(StructImpl.java:230) 
at lucee.runtime.op.Duplicator.duplicate(Duplicator.java:131) 
at lucee.runtime.type.StructImpl.copy(StructImpl.java:242) 
at lucee.runtime.type.StructImpl.duplicate(StructImpl.java:230) 
at lucee.runtime.op.Duplicator.duplicate(Duplicator.java:131) 
at lucee.runtime.type.StructImpl.copy(StructImpl.java:242) 
at lucee.runtime.type.StructImpl.duplicate(StructImpl.java:230) 
at lucee.runtime.op.Duplicator.duplicate(Duplicator.java:131) 
at lucee.runtime.type.StructImpl.copy(StructImpl.java:242) 
at lucee.runtime.type.StructImpl.duplicate(StructImpl.java:230) 
at lucee.runtime.op.Duplicator.duplicate(Duplicator.java:131) 
at lucee.runtime.op.Duplicator.duplicateMap(Duplicator.java:232) 
at lucee.runtime.op.Duplicator.duplicateMap(Duplicator.java:219) 
at lucee.runtime.op.Duplicator.duplicate(Duplicator.java:135) 
at lucee.runtime.functions.struct.Duplicate.call(Duplicate.java:36) 
at performanceanalyzer.memory_cfm$cf.call(/lucee_server_plugin_directory/PerformanceAnalyzer/memory.cfm:48) 
at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1056) 
at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:948) 
at lucee.runtime.PageContextImpl.doInclude(PageContextImpl.java:929) 
at performanceanalyzer.action_cfc$cf.udfCall(/lucee_plugin_directory/PerformanceAnalyzer/Action.cfc:47) 
at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112) 
at lucee.runtime.type.UDFImpl._call(UDFImpl.java:350) 
at lucee.runtime.type.UDFImpl.call(UDFImpl.java:223) 
at lucee.runtime.ComponentImpl._call(ComponentImpl.java:696) 
at lucee.runtime.ComponentImpl._call(ComponentImpl.java:584) 
at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1931) 
at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787) 
at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1775) 
at plugin_cfm$cf.call(/admin/plugin.cfm:78)
...
Caused by: org.hibernate.LazyInitializationException: failed to lazily initialize a collection of role: customer.datasources, no session or session was closed ... 114 more

And the 1st tag context;

image
image1114Ă—375 20.6 KB

I have I misconfigured something?

2

Can you post the full stack trace? It would appear this is an ORM application and something is trying to load hibernate. I’m guessing related to the duplication of the session variables.

3

The stack trace that is in the error that I see within the Administrator is in the above message - albeit in one long line - as opposed to how it “looks” on screen.

I suppose I could output the exception by hacking the extension’s code?
Is this what you meant - or am I completely missing something obvious?

4

Apologies, I completely missed the stack trace without the line breaks. I have edited your post to introduce line breaks (and trimmed some irrelevant parts).

As I suspected, the duplicate is causing this. I don’t think there is a good fix for this. I would be rather wary of what the plugin is doing. It seems to be duplicating the entire session scope for every session which seems very heavy handed. The error comes from Hibernate itself when trying to initialize a duplicated Hibernate entity which is stored in session.

1 Like
5

@Gavin_Baumanis What version of the Hibernate extension do you have installed? The Lucee Hibernate extension v5.4.x is known to close the ORM session on transaction end. So trying to access any ORM entity with lazyloaded properties after transaction end would throw this error.

https://luceeserver.atlassian.net/browse/LDEV-4017

6

Thanks for the prompt to check the Hibernate version, I am using 3.5.5.87.
I couldn’t get a v5 extension to work in my application.