5.3.9.160 underload causing java.lang.NullPointerException

fingersdancing · September 1, 2022, 2:37am

What we have found is that if we send 10 requests concurrently over 2k requests we will get about 2 to 6 requests which just die with a 500. They do not appear to hit our application code at all.

When moving back to 5.3.9.133 and doing the exact same load or even higher we get no errors.

The stack trace is

java.lang.NullPointerException
lucee.runtime.CFMLFactoryImpl.getPageContextImpl(CFMLFactoryImpl.java:182)
lucee.runtime.engine.CFMLEngineImpl._service(CFMLEngineImpl.java:1166)
lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:1144)
lucee.loader.engine.CFMLEngineWrapper.serviceCFML(CFMLEngineWrapper.java:97)
lucee.loader.servlet.CFMLServlet.service(CFMLServlet.java:51)
javax.servlet.http.HttpServlet.service(HttpServlet.java:590)
io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
org.cfmlprojects.regexpathinfofilter.RegexPathInfoFilter.doFilter(RegexPathInfoFilter.java:47)
io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:257)
io.undertow.servlet.handlers.ServletInitialHandler.dispatchToPath(ServletInitialHandler.java:182)
io.undertow.servlet.spec.RequestDispatcherImpl.forwardImpl(RequestDispatcherImpl.java:225)
io.undertow.servlet.spec.RequestDispatcherImpl.forwardImplSetup(RequestDispatcherImpl.java:147)
io.undertow.servlet.spec.RequestDispatcherImpl.forward(RequestDispatcherImpl.java:110)
org.cfmlprojects.regexpathinfofilter.RegexPathInfoFilter.doFilter(RegexPathInfoFilter.java:45)
io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
jdk.internal.reflect.GeneratedMethodAccessor65.invoke(Unknown Source)
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
java.lang.reflect.Method.invoke(Unknown Source)
com.intergral.fusionreactor.j2ee.filterchain.WrappedFilterChain.doFilter(WrappedFilterChain.java:134)
com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doNext(FusionReactorRequestHandler.java:772)
com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doHttpServletRequest(FusionReactorRequestHandler.java:344)
com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doFusionRequest(FusionReactorRequestHandler.java:207)
com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.handle(FusionReactorRequestHandler.java:809)
com.intergral.fusionreactor.j2ee.filter.FusionReactorCoreFilter.doFilter(FusionReactorCoreFilter.java:36)
jdk.internal.reflect.GeneratedMethodAccessor64.invoke(Unknown Source)
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
java.lang.reflect.Method.invoke(Unknown Source)
com.intergral.fusionreactor.j2ee.filterchain.WrappedFilterChain.doFilter(WrappedFilterChain.java:71)
jdk.internal.reflect.GeneratedMethodAccessor63.invoke(Unknown Source)
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
java.lang.reflect.Method.invoke(Unknown Source)
com.intergral.fusionreactor.agent.filter.FusionReactorStaticFilter.doFilter(FusionReactorStaticFilter.java:54)
com.intergral.fusionreactor.agent.pointcuts.NewFilterChainPointCut$1.invoke(NewFilterChainPointCut.java:42)
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java)
io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:117)
io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
io.undertow.servlet.handlers.SendErrorPageHandler.handleRequest(SendErrorPageHandler.java:52)
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:275)
io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:79)
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:134)
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:131)
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)
io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:255)
io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:79)
io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:100)
io.undertow.server.Connectors.executeRootHandler(Connectors.java:387)
io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:852)
org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2019)
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1558)
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1449)
org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1280)
java.lang.Thread.run(Unknown Source)

bdw429s · September 1, 2022, 3:57am

Looking at the blame for that line of code, it seems this was found and fixed last week.
https://luceeserver.atlassian.net/browse/LDEV-4162

Try testing the 5.3.9.162 snapshot.

fingersdancing · September 1, 2022, 4:31am

@bdw429s tested with 5.3.9-SNAPSHOT+162 and the 500’s no longer appear.

Thanks for the suggestion

bennadel · November 8, 2022, 8:04pm

Been running into this as well. Rando Null pointer exceptions with the error message:

08-Nov-2022 20:02:09.618 SEVERE [http-nio-8500-exec-36] org.apache.catalina.core.StandardWrapperValve.invoke Servlet.service() for servlet [CFMLServlet] in context with path [] threw exception
java.lang.NullPointerException
	at lucee.runtime.CFMLFactoryImpl.getPageContextImpl(CFMLFactoryImpl.java:182)
	at lucee.runtime.engine.CFMLEngineImpl._service(CFMLEngineImpl.java:1166)
	at lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:1144)
	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:764)
	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:197)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:769)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:890)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1789)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:750)

Glad to hear a fix is in the works.

bdw429s · November 8, 2022, 8:16pm

@bennadel I believe the fix is actually released! Please upgrade to Lucee 5.3.9.166 and give it a test!
https://lucee.daemonite.io/t/lucee-5-3-9-166-stable-release/11319

bennadel · November 8, 2022, 8:38pm

Ah, ok great! I’ll give it a look