luceedebug
luceedebug copied to clipboard
softwareCobbler
java.lang.NullPointerException on Lucee Restart
When restarting Lucee via the admin UI, the NullPointerException below is thrown. The service starts as expected and Luceedebug is fully operational until restarting.
If I remove these 2 jvm args, the service will restart as expected,
"-agentlib:jdwp=transport=dt_socket,server=y,suspend=n,address=localhost:9999",
"-javaagent:/app/lib/luceedebug.jar=jdwpHost=localhost,jdwpPort=9999,debugHost=0.0.0.0,debugPort=10000,jarPath=/app/lib/luceedebug.jar"
Lucee 5.3.10.97 Lucee Debug @ https://github.com/softwareCobbler/luceedebug/commit/084fa57ad8bfa5e8ec230a1658e656ae14024c63 Docker Commandbox Ubuntu Linux
[INFO] 2023-05-26T05:29:33Z - Starting server using generated script: /usr/bin/startup.sh
Listening for transport dt_socket at address: 9999
[luceedebug] fs is case sensitive: true
[luceedebug] agent premain complete
[INFO ] runwar.server: ******************************************************************************
[INFO ] runwar.server: Starting RunWAR 4.8.3
[INFO ] runwar.server: Binding HTTP on 0.0.0.0:80
[INFO ] runwar.server: Enabling HTTP/2
[INFO ] runwar.server: Binding SSL on 0.0.0.0:443
[INFO ] runwar.server: Servlet Context: /
[INFO ] runwar.server: Log Directory: /usr/lib/serverHome/logs
[INFO ] runwar.server: ******************************************************************************
[INFO ] runwar.config: Parsing '/usr/lib/serverHome/WEB-INF/web.xml'
[INFO ] runwar.server: Creating deployment [default] in /app
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.apache.felix.framework.ext.ClassPathExtenderFactory$DefaultClassLoaderExtender (file:/usr/lib/serverHome/WEB-INF/lib/lucee.jar) to method java.net.URLClassLoader.addURL(java.net.URL)
WARNING: Please consider reporting this to the maintainers of org.apache.felix.framework.ext.ClassPathExtenderFactory$DefaultClassLoaderExtender
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
[INFO ] runwar.context: [luceedebug] Loaded luceedebug.coreinject.DebugManager@2b10ace9 with ClassLoader 'lucee.core [49]'
[INFO ] runwar.context: [luceedebug] attempting jdwp self connect to jdwp on localhost:9999...
[INFO ] runwar.context: [luceedebug] jdwp self connect OK
[INFO ] runwar.server: ******************************************************************************
[INFO ] runwar.server: *** starting 'stop' listener thread - Host: 0.0.0.0 - Socket: 34723
[INFO ] runwar.server: ******************************************************************************
[INFO ] runwar.server: Server is up - http-port:80 https-port:443 stop-port:34723 PID:1 version 4.8.3
[ERROR] runwar.context: java.lang.NullPointerException
[ERROR] runwar.context: at luceedebug.LuceeTransformer.transform(LuceeTransformer.java:96)
[ERROR] runwar.context: at java.instrument/java.lang.instrument.ClassFileTransformer.transform(ClassFileTransformer.java:246)
[ERROR] runwar.context: at java.instrument/sun.instrument.TransformerManager.transform(TransformerManager.java:188)
[ERROR] runwar.context: at java.instrument/sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:563)
[ERROR] runwar.context: at java.base/java.lang.ClassLoader.defineClass1(Native Method)
[ERROR] runwar.context: at java.base/java.lang.ClassLoader.defineClass(ClassLoader.java:1017)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.defineClass(BundleWiringImpl.java:2312)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.defineClassParallel(BundleWiringImpl.java:2130)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.findClass(BundleWiringImpl.java:2064)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl.findClassOrResourceByDelegation(BundleWiringImpl.java:1533)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl.access$300(BundleWiringImpl.java:78)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.loadClass(BundleWiringImpl.java:1950)
[ERROR] runwar.context: at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:522)
[ERROR] runwar.context: at java.base/java.lang.Class.getDeclaredMethods0(Native Method)
[ERROR] runwar.context: at java.base/java.lang.Class.privateGetDeclaredMethods(Class.java:3166)
[ERROR] runwar.context: at java.base/java.lang.Class.getMethodsRecursive(Class.java:3307)
[ERROR] runwar.context: at java.base/java.lang.Class.getMethod0(Class.java:3293)
[ERROR] runwar.context: at java.base/java.lang.Class.getMethod(Class.java:2106)
[ERROR] runwar.context: at lucee.loader.engine.CFMLEngineFactory.getEngine(CFMLEngineFactory.java:1468)
[ERROR] runwar.context: at lucee.loader.engine.CFMLEngineFactory.initEngine(CFMLEngineFactory.java:384)
[ERROR] runwar.context: at lucee.loader.engine.CFMLEngineFactory._restart(CFMLEngineFactory.java:617)
[ERROR] runwar.context: at lucee.loader.engine.CFMLEngineFactory.restart(CFMLEngineFactory.java:596)
[ERROR] runwar.context: at lucee.runtime.config.XMLConfigAdmin.restart(XMLConfigAdmin.java:3947)
[ERROR] runwar.context: at lucee.runtime.tag.Admin.doRestart(Admin.java:947)
[ERROR] runwar.context: at lucee.runtime.tag.Admin._doStartTag(Admin.java:876)
[ERROR] runwar.context: at lucee.runtime.tag.Admin.doStartTag(Admin.java:364)
[ERROR] runwar.context: at restart_cfm$cf.__luceedebug__call(/admin/restart.cfm:6)
[ERROR] runwar.context: at restart_cfm$cf.call(/admin/restart.cfm)
[ERROR] runwar.context: at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:1025)
[ERROR] runwar.context: at lucee.runtime.PageContextImpl._doInclude(PageContextImpl.java:948)
[ERROR] runwar.context: at lucee.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:219)
[ERROR] runwar.context: at lucee.runtime.listener.MixedAppListener.onRequest(MixedAppListener.java:44)
[ERROR] runwar.context: at lucee.runtime.PageContextImpl.execute(PageContextImpl.java:2493)
[ERROR] runwar.context: at lucee.runtime.PageContextImpl._execute(PageContextImpl.java:2478)
[ERROR] runwar.context: at lucee.runtime.PageContextImpl.executeCFML(PageContextImpl.java:2449)
[ERROR] runwar.context: at lucee.runtime.engine.Request.exe(Request.java:45)
[ERROR] runwar.context: at lucee.runtime.engine.CFMLEngineImpl._service(CFMLEngineImpl.java:1216)
[ERROR] runwar.context: at lucee.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:1162)
[ERROR] runwar.context: at lucee.loader.engine.CFMLEngineWrapper.serviceCFML(CFMLEngineWrapper.java:97)
[ERROR] runwar.context: at lucee.loader.servlet.CFMLServlet.service(CFMLServlet.java:51)
[ERROR] runwar.context: at javax.servlet.http.HttpServlet.service(HttpServlet.java:590)
[ERROR] runwar.context: at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
[ERROR] runwar.context: at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
[ERROR] runwar.context: at org.cfmlprojects.regexpathinfofilter.RegexPathInfoFilter.doFilter(RegexPathInfoFilter.java:47)
[ERROR] runwar.context: at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:67)
[ERROR] runwar.context: at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
[ERROR] runwar.context: at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:176)
[ERROR] runwar.context: at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145)
[ERROR] runwar.context: at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92)
[ERROR] runwar.context: at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:405)
[ERROR] runwar.context: at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:67)
[ERROR] runwar.context: at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
[ERROR] runwar.context: at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
[ERROR] runwar.context: at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
[ERROR] runwar.context: at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
[ERROR] runwar.context: at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
[ERROR] runwar.context: at runwar.undertow.SSLClientCertHeaderHandler.handleRequest(SSLClientCertHeaderHandler.java:144)
[ERROR] runwar.context: at io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
[ERROR] runwar.context: at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:117)
[ERROR] runwar.context: at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
[ERROR] runwar.context: at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
[ERROR] runwar.context: at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
[ERROR] runwar.context: at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
[ERROR] runwar.context: at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
[ERROR] runwar.context: at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
[ERROR] runwar.context: at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
[ERROR] runwar.context: at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
[ERROR] runwar.context: at io.undertow.servlet.handlers.SendErrorPageHandler.handleRequest(SendErrorPageHandler.java:52)
[ERROR] runwar.context: at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
[ERROR] runwar.context: at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:275)
[ERROR] runwar.context: at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:79)
[ERROR] runwar.context: at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:134)
[ERROR] runwar.context: at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:131)
[ERROR] runwar.context: at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
[ERROR] runwar.context: at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
[ERROR] runwar.context: at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)
[ERROR] runwar.context: at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:255)
[ERROR] runwar.context: at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:79)
[ERROR] runwar.context: at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:100)
[ERROR] runwar.context: at io.undertow.server.Connectors.executeRootHandler(Connectors.java:393)
[ERROR] runwar.context: at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:852)
[ERROR] runwar.context: at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
[ERROR] runwar.context: at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2019)
[ERROR] runwar.context: at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1558)
[ERROR] runwar.context: at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1449)
[ERROR] runwar.context: at org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1282)
[ERROR] runwar.context: at java.base/java.lang.Thread.run(Thread.java:829)
We null out a ref under the assumption we will never need it again; but then need it again, upon this reset action. Thanks for the report, will investigate.
We've started having this issue as well as soon as the container starts.
Attaching the debugger as soon as jdwp self connect OK is logged is a workaround, but it's not a great experience.
We have this looking like it's fixed after some local testing, on branch handle-lucee-restart. Let us know if you encounter any issues, or if it appears fixed on your end, too.
Hey @softwareCobbler sorry it took me so long to give this a try but after trying your branch, the application fails to start with a different error.
The app was compiled from your branch on a Mac with ./gradlew shadowjar
Here's the error:
[ERROR] runwar.context: java.lang.reflect.InvocationTargetException
[ERROR] runwar.context: at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[ERROR] runwar.context: at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
[ERROR] runwar.context: at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
[ERROR] runwar.context: at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
[ERROR] runwar.context: at luceedebug.LuceeTransformer.transform(LuceeTransformer.java:109)
[ERROR] runwar.context: at java.instrument/java.lang.instrument.ClassFileTransformer.transform(ClassFileTransformer.java:246)
[ERROR] runwar.context: at java.instrument/sun.instrument.TransformerManager.transform(TransformerManager.java:188)
[ERROR] runwar.context: at java.instrument/sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:563)
[ERROR] runwar.context: at java.base/java.lang.ClassLoader.defineClass1(Native Method)
[ERROR] runwar.context: at java.base/java.lang.ClassLoader.defineClass(ClassLoader.java:1017)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.defineClass(BundleWiringImpl.java:2344)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.defineClassParallel(BundleWiringImpl.java:2162)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.findClass(BundleWiringImpl.java:2096)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl.findClassOrResourceByDelegation(BundleWiringImpl.java:1565)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl.access$300(BundleWiringImpl.java:79)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.loadClass(BundleWiringImpl.java:1982)
[ERROR] runwar.context: at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:522)
[ERROR] runwar.context: at java.base/java.lang.Class.getDeclaredMethods0(Native Method)
[ERROR] runwar.context: at java.base/java.lang.Class.privateGetDeclaredMethods(Class.java:3166)
[ERROR] runwar.context: at java.base/java.lang.Class.getMethodsRecursive(Class.java:3307)
[ERROR] runwar.context: at java.base/java.lang.Class.getMethod0(Class.java:3293)
[ERROR] runwar.context: at java.base/java.lang.Class.getMethod(Class.java:2106)
[ERROR] runwar.context: at lucee.loader.engine.CFMLEngineFactory.getEngine(CFMLEngineFactory.java:1448)
[ERROR] runwar.context: at lucee.loader.engine.CFMLEngineFactory._getCore(CFMLEngineFactory.java:565)
[ERROR] runwar.context: at lucee.loader.engine.CFMLEngineFactory.initEngine(CFMLEngineFactory.java:370)
[ERROR] runwar.context: at lucee.loader.engine.CFMLEngineFactory.initEngineIfNecessary(CFMLEngineFactory.java:262)
[ERROR] runwar.context: at lucee.loader.engine.CFMLEngineFactory.getInstance(CFMLEngineFactory.java:168)
[ERROR] runwar.context: at lucee.loader.engine.CFMLEngineFactory.getInstance(CFMLEngineFactory.java:202)
[ERROR] runwar.context: at lucee.loader.servlet.LuceeServlet.init(LuceeServlet.java:42)
[ERROR] runwar.context: at io.undertow.servlet.core.LifecyleInterceptorInvocation.proceed(LifecyleInterceptorInvocation.java:117)
[ERROR] runwar.context: at io.undertow.servlet.core.ManagedServlet$DefaultInstanceStrategy.start(ManagedServlet.java:305)
[ERROR] runwar.context: at io.undertow.servlet.core.ManagedServlet.createServlet(ManagedServlet.java:145)
[ERROR] runwar.context: at io.undertow.servlet.core.DeploymentManagerImpl$2.call(DeploymentManagerImpl.java:588)
[ERROR] runwar.context: at io.undertow.servlet.core.DeploymentManagerImpl$2.call(DeploymentManagerImpl.java:559)
[ERROR] runwar.context: at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:42)
[ERROR] runwar.context: at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
[ERROR] runwar.context: at io.undertow.servlet.core.DeploymentManagerImpl.start(DeploymentManagerImpl.java:601)
[ERROR] runwar.context: at runwar.Server.startServer(Server.java:553)
[ERROR] runwar.context: at runwar.Start.main(Start.java:123)
[ERROR] runwar.context: Caused by: java.lang.NoClassDefFoundError: luceedebug_shadow/com/google/common/collect/MapMaker
[ERROR] runwar.context: at luceedebug.coreinject.DebugManager.<init>(DebugManager.java:484)
[ERROR] runwar.context: ... 39 more
[ERROR] runwar.context: Caused by: java.lang.ClassNotFoundException: luceedebug_shadow.com.google.common.collect.MapMaker not found by lucee.core [48]
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl.findClassOrResourceByDelegation(BundleWiringImpl.java:1597)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl.access$300(BundleWiringImpl.java:79)
[ERROR] runwar.context: at org.apache.felix.framework.BundleWiringImpl$BundleClassLoader.loadClass(BundleWiringImpl.java:1982)
[ERROR] runwar.context: at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:522)
[ERROR] runwar.context: ... 40 more
[INFO ] runwar.server: ******************************************************************************
[INFO ] runwar.server: *** stopping server 'www' (socket 45975)
[INFO ] runwar.server: ******************************************************************************