Lucee 6 - Regression at lucee.runtime.PagePro - Receiver class does not define or inherit an implementation of the resolved method abstract getSubname()Ljava/lang/String; of interface lucee.runtime.PagePro

quantumleapchicago · July 11, 2023, 11:09am

Hey esteemed Lucee Devs!
Sorry to put this on your plate, but I think we found a bug.

OS: Windows 2019
Java Version: Tested with both OpenJDK 11.0.11 (bundled) and Oracle 11.0.18 (64-bit)
Tomcat Version: Apache Tomcat 9.0.45
Lucee Version: 6.0.0.503-RC

We have a custom component we use for some encryption, which works fine in 5.4. (both 5.4.0.80 and 5.4.1.8), but breaks in 6.0.

The cfc of one of our models includes a simple call which is now failing:

<cfset var classEncryption = createObject("component", "Encryption")>

and that CFC is pretty straightforward:

<cfcomponent displayname="Encryption" hint="Encryption" accessors="true">
	<cfset secretkeys = "obviouslyredacted" />
        ...
	<cffunction name="Encrypt" access="public" output="no" hint="" >
        ...
        <cffunction name="Decrypt" access="public" output="no" hint="" >
        ...

Error Message: Receiver class cfc.encryption_cfc$cf$7 does not define or inherit an implementation of the resolved method abstract getSubname()Ljava/lang/String; of interface lucee.runtime.PagePro.

Stack Trace:

lucee.runtime.exp.NativeException: Receiver class cfc.encryption_cfc$cf$7 does not define or inherit an implementation of the resolved method abstract getSubname()Ljava/lang/String; of interface lucee.runtime.PagePro. at lucee.runtime.ComponentImpl.<init>(ComponentImpl.java:195) at cfc.encryption_cfc$cf$7.newInstance(/cfc/encryption.cfc:1) at lucee.runtime.component.ComponentLoader.initComponent(ComponentLoader.java:653) at lucee.runtime.component.ComponentLoader._loadComponent(ComponentLoader.java:577) at lucee.runtime.component.ComponentLoader.load(ComponentLoader.java:496) at lucee.runtime.component.ComponentLoader._search(ComponentLoader.java:261) at lucee.runtime.component.ComponentLoader._search(ComponentLoader.java:191) at lucee.runtime.component.ComponentLoader.searchComponent(ComponentLoader.java:84) at lucee.runtime.PageContextImpl.loadComponent(PageContextImpl.java:3295) at lucee.runtime.functions.other.CreateObject.doComponent(CreateObject.java:148) at lucee.runtime.functions.other.CreateObject.call(CreateObject.java:70) at lucee.runtime.functions.other.CreateObject.call(CreateObject.java:49) at cfc.member_cfc$cf$3.udfCall5(/cfc/Member.cfc:2381) at cfc.member_cfc$cf$3.udfCall(/cfc/Member.cfc) at lucee.runtime.type.UDFImpl.implementation(UDFImpl.java:112) at lucee.runtime.type.UDFImpl._call(UDFImpl.java:348) at lucee.runtime.type.UDFImpl.call(UDFImpl.java:223) at lucee.runtime.ComponentImpl._call(ComponentImpl.java:665) at lucee.runtime.ComponentImpl._call(ComponentImpl.java:587) at lucee.runtime.ComponentImpl.call(ComponentImpl.java:1962) at lucee.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:787) at lucee.runtime.PageContextImpl.getFunction(PageContextImpl.java:1777) at common.header_cfm$cf.call(/common/header.cfm:7) at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1027) at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:950) at lucee.runtime.PageContextImpl.doInclude(PageContextImpl.java:931) at html.mystores_cfm$cf.call(/html/MyStores.cfm:172) at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1027) at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:950) at lucee.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:221) at lucee.runtime.listener.MixedAppListener.onRequest(MixedAppListener.java:44) at lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2494) at lucee.runtime.PageContextImpl._execute(PageContextImpl.java:2480) at lucee.runtime.PageContextImpl.executeCFML(PageContextImpl.java:2451) at lucee.runtime.engine.Request.exe(Request.java:45) at lucee.runtime.engine.CFMLEngineImpl._service(CFMLEngineImpl.java:1218) at lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:1164) at lucee.loader.engine.CFMLEngineWrapper.serviceCFML(CFMLEngineWrapper.java:97) at lucee.loader.servlet.CFMLServlet.service(CFMLServlet.java:51) at javax.servlet.http.HttpServlet.service(HttpServlet.java:733) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357) at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:433) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1707) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.base/java.lang.Thread.run(Thread.java:834) Caused by: java.lang.AbstractMethodError: Receiver class cfc.encryption_cfc$cf$7 does not define or inherit an implementation of the resolved method abstract getSubname()Ljava/lang/String; of interface lucee.runtime.PagePro.

Note: Not sure why Oracle Java 11.0.18 shows the letter L in the error (the resolved method abstract getSubname()Ljava/lang/String; of interface lucee.runtime.PagePro), versus with OpenJDK we were seeing the error formatted better (the resolved method ‘abstract java.lang.String getSubname()’ of interface lucee.runtime.PagePro), but I think that’s just a formatting thing.

I tried making our component implement the interfaces: lucee.runtime, lucee.runtime.PagePro. I did not try to make it extend another component (such as org/lucee/cfml/HelperBase.cfc) as I have no idea about all that – most of our code is web and procedural, so some of the object oriented bits and deeper workings of Lucee engine escape me.

Lucee 6, I did switch to Single Admin mode (although we run 3 separate ‘contexts’) and had to rebuild the Default Caches – but other than that, it seems all the Lucee server settings mirror that in our 5.4.1.8 production environment. Let me know if we should try switching back to Multimode.

We are experimenting with Lucee 6 and Oracle Java due to some instability we’ve had now that we are using Lucee 5.4 (both 5.4.0.80 and 5.4.1.8) in production – under ‘load’, it kills Coldbox MVC middleware we’re using, although RAM/CPU seems good and thread / request management seems OK (we get better results with higher request thresholds, but nothing concrete, and tinkering with the queue / Tomcat thread max doesn’t seem to make much of a difference). So far, Lucee 5.4.1.8 with Oracle Java 11.0.18 seems more stable, but it’s too early to tell.

Any suggestions?

Hopefully this helps you as a report of 6.0 testing in the field. Happy to provide further details or testing. Hopefully I didn’t miss something remedial, but happy to take that critique as well. Thanks!

Zackster · July 11, 2023, 11:19am

We love a good bug report!

please go ahead a file a bug report

we’ll need a reduced test case / repo to be able to address it

as for the load testing, any specific exceptions being thrown?

quantumleapchicago · July 11, 2023, 11:36am

Thanks for the quick response Zac!
I will work on a reference reproduction and file a bug report later today.

Load testing - we get a missing key error in exception.log, where that key is part of the Coldbox middleware.

“ERROR”,“ajp-nio-127.0.0.1-8009-exec-1”,“07/11/2023”,“06:24:28”,“”,"The key [cbController] does not exist, only the following keys are available: [applicationname, {other scopes we use}.;lucee.runtime.exp.ExpressionException: The key [cbController] does not exist, only the following keys are available: [applicationname, {other scopes we use}].

I am thinking it’s pruing the object cache, I have recently told it NOT to do that, but it’s only caching a handful of objects and not even close to touching memory limits. FusionReactor shows threads being created, but they’re never really destroyed… I tried to address threadpool settings but, there’s not a lot of documentation other than tinkering with Tomcat max connections, which we’ve set high and low.

Any insight or thoughts appreciated. I’d hate to resort to asking ChatGPT what it thinks about this

Zackster · July 11, 2023, 11:52am

you can try bumping up the log levels for Application.log to TRACE, which will be very verbose but might have some clues.

but before doing that, I’d figure out just how long you need to run the load testing before it reproduces the problem(s).

tho once the TRACE logging is enabled, it will slows things down, so it might behave differently

might be worth adding some logging to onApplicationEnd, sounds a bit like the application is expiring and there’s a race condition or something?

quantumleapchicago · July 12, 2023, 9:00pm

Some updates to truly close the loop on this:

Not submitting a bug report, as I believe that this is something funky on our side, and not with 6.0 specifically. Some data points:

Using Coldbox HMVC, which then breaks out the models, views, controller, so even a ‘reduced test case’ is relying on third party framework.
I discovered that there are some underlying issues on 5.4 with our CFC and data types.
We’re not actually calling the CFC I thought, we’re calling a precompiled java class
etc etc

Load / stability issue was due to Coldbox and a known issue with it, sometimes you have to manually reinit the framework - so Lucee / Tomcat wasn’t dying, it was specific to our application with tons of logic.

No reply needed, just putting this here for future time travelers who stumble on this thread.