0003334: Snapshot 3.1.s090206: NullPointerException in Logging

Mantis - Resin
Viewing Issue Advanced Details

ID:	Category:	Severity:	Reproducibility:	Date Submitted:	Last Update:
3334		minor	always	02-09-09 13:42	02-25-09 17:01

Reporter:	stbu	Platform:
Assigned To:	ferg	OS:
Priority:	normal	OS Version:
Status:	closed	Product Version:	3.1.9
Product Build:		Resolution:	fixed
Projection:	none
ETA:	none	Fixed in Version:	4.0.0

Summary:	0003334: Snapshot 3.1.s090206: NullPointerException in Logging
Description:	With the recent Snapshots of 3.1 (not just only s090206), I receive very often RuntimeException / NullPointerException when Resin is stopping due to Configuration change. Testcase, how to reproduce it. 1.) Add the following Standard Output Redirection to resin.conf under the top level <resin> tag <stdout-log path="${resin.root}/logs/stdout.log" rollover-period="3D" rollover-count="3"/> <stderr-log path="${resin.root}/logs/stderr.log" rollover-period="3D" rollover-count="3"/> 2.) Add an extensive Logging for a web-app. The attached sample WAR contains the following Logging directive. <web-app xmlns="http://caucho.com/ns/resin" [^] xmlns:resin="http://caucho.com/ns/resin/core"> [^] <!-- - Debug Logging with a heavily loaded format attribute to get more information ... --> <log level="finest" path="WEB-INF/debug_${webApp.name}.log" timestamp="[%H:%M:%S.%s] {%{thread}} " format="[${app.contextPath}] ${log.level} ${log.sourceClassName} (${log.sourceMethodName}) ${log.message}"> <logger name="com.caucho.server" level="finest"/> </log> </web-app> 3.) Start Resin and wait until the test web-app is initialized. So far, {resin.root}/logs/stderr.log should be empty. 4.) Now, make a change in resin.conf so that Resin will detect the configuration change and force a restart. During the shutdown phase, many RuntimeException / NullPointerException are thrown which are now logged to {resin.root}/logs/stderr.log file. See below except. The attached WAR file could be used to reproduce this issue when performing above mentioned steps.
Steps To Reproduce:
Additional Information:	java.lang.RuntimeException: java.lang.NullPointerException at com.caucho.log.ELFormatter.format(ELFormatter.java:96) at com.caucho.log.StreamHandler.publish(StreamHandler.java:93) at com.caucho.log.SubHandler.publish(SubHandler.java:60) at com.caucho.log.EnvironmentLogger.log(EnvironmentLogger.java:329) at java.util.logging.Logger.doLog(Logger.java:494) at java.util.logging.Logger.log(Logger.java:517) at com.caucho.lifecycle.Lifecycle.toStop(Lifecycle.java:643) at com.caucho.server.webapp.WebApp.stop(WebApp.java:2788) at com.caucho.server.webapp.WebApp.destroy(WebApp.java:2797) at com.caucho.server.deploy.DeployController.stopImpl(DeployController.java:750) at com.caucho.server.deploy.AbstractDeployControllerStrategy.stop(AbstractDeployControllerStrategy.java:77) at com.caucho.server.deploy.DeployController.stop(DeployController.java:571) at com.caucho.server.deploy.DeployContainer.stop(DeployContainer.java:380) at com.caucho.server.webapp.WebAppContainer.stop(WebAppContainer.java:1111) at com.caucho.server.host.Host.stop(Host.java:559) at com.caucho.server.host.Host.destroy(Host.java:576) at com.caucho.server.deploy.DeployController.stopImpl(DeployController.java:750) at com.caucho.server.deploy.DeployController.restartImpl(DeployController.java:628) at com.caucho.server.deploy.StartAutoRedeployAutoStrategy.request(StartAutoRedeployAutoStrategy.java:125) at com.caucho.server.deploy.DeployController.request(DeployController.java:600) at com.caucho.server.host.HostContainer.getHost(HostContainer.java:372) at com.caucho.server.cluster.Server.getWebApp(Server.java:1084) at com.caucho.server.cluster.Server.getDefaultWebApp(Server.java:1065) at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:259) at com.caucho.server.port.TcpConnection.run(TcpConnection.java:682) at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:730) at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:649) at java.lang.Thread.run(Thread.java:619) Caused by: java.lang.NullPointerException at com.caucho.webbeans.manager.WebBeansContainer.findByName(WebBeansContainer.java:629) at com.caucho.webbeans.el.WebBeansContextResolver.getValue(WebBeansContextResolver.java:85) at com.caucho.el.StackELResolver.getValue(StackELResolver.java:143) at com.caucho.el.StackELResolver.getValue(StackELResolver.java:143) at com.caucho.el.IdExpr.getValue(IdExpr.java:100) at com.caucho.el.ArrayResolverExpr.getValue(ArrayResolverExpr.java:139) at com.caucho.el.PathExpr.getValue(PathExpr.java:142) at com.caucho.el.Expr.evalString(Expr.java:276) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:103) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.log.ELFormatter.format(ELFormatter.java:93) ... 27 more java.lang.RuntimeException: java.lang.NullPointerException at com.caucho.log.ELFormatter.format(ELFormatter.java:96) at com.caucho.log.StreamHandler.publish(StreamHandler.java:93) at com.caucho.log.SubHandler.publish(SubHandler.java:60) at com.caucho.log.EnvironmentLogger.log(EnvironmentLogger.java:329) at java.util.logging.Logger.doLog(Logger.java:494) at java.util.logging.Logger.log(Logger.java:517) at com.caucho.lifecycle.Lifecycle.toDestroy(Lifecycle.java:698) at com.caucho.server.webapp.WebApp.destroy(WebApp.java:2799) at com.caucho.server.deploy.DeployController.stopImpl(DeployController.java:750) at com.caucho.server.deploy.AbstractDeployControllerStrategy.stop(AbstractDeployControllerStrategy.java:77) at com.caucho.server.deploy.DeployController.stop(DeployController.java:571) at com.caucho.server.deploy.DeployContainer.stop(DeployContainer.java:380) at com.caucho.server.webapp.WebAppContainer.stop(WebAppContainer.java:1111) at com.caucho.server.host.Host.stop(Host.java:559) at com.caucho.server.host.Host.destroy(Host.java:576) at com.caucho.server.deploy.DeployController.stopImpl(DeployController.java:750) at com.caucho.server.deploy.DeployController.restartImpl(DeployController.java:628) at com.caucho.server.deploy.StartAutoRedeployAutoStrategy.request(StartAutoRedeployAutoStrategy.java:125) at com.caucho.server.deploy.DeployController.request(DeployController.java:600) at com.caucho.server.host.HostContainer.getHost(HostContainer.java:372) at com.caucho.server.cluster.Server.getWebApp(Server.java:1084) at com.caucho.server.cluster.Server.getDefaultWebApp(Server.java:1065) at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:259) at com.caucho.server.port.TcpConnection.run(TcpConnection.java:682) at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:730) at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:649) at java.lang.Thread.run(Thread.java:619) Caused by: java.lang.NullPointerException at com.caucho.webbeans.manager.WebBeansContainer.findByName(WebBeansContainer.java:629) at com.caucho.webbeans.el.WebBeansContextResolver.getValue(WebBeansContextResolver.java:85) at com.caucho.el.StackELResolver.getValue(StackELResolver.java:143) at com.caucho.el.StackELResolver.getValue(StackELResolver.java:143) at com.caucho.el.IdExpr.getValue(IdExpr.java:100) at com.caucho.el.ArrayResolverExpr.getValue(ArrayResolverExpr.java:139) at com.caucho.el.PathExpr.getValue(PathExpr.java:142) at com.caucho.el.Expr.evalString(Expr.java:276) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:103) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.log.ELFormatter.format(ELFormatter.java:93) ... 26 more java.lang.RuntimeException: java.lang.NullPointerException at com.caucho.log.ELFormatter.format(ELFormatter.java:96) at com.caucho.log.StreamHandler.publish(StreamHandler.java:93) at com.caucho.log.SubHandler.publish(SubHandler.java:60) at com.caucho.log.EnvironmentLogger.log(EnvironmentLogger.java:329) at java.util.logging.Logger.doLog(Logger.java:494) at java.util.logging.Logger.log(Logger.java:517) at java.util.logging.Logger.finest(Logger.java:1100) at com.caucho.server.cluster.Server.clearCache(Server.java:1567) at com.caucho.server.webapp.WebApp.clearCache(WebApp.java:2135) at com.caucho.server.webapp.WebApp.destroy(WebApp.java:2802) at com.caucho.server.deploy.DeployController.stopImpl(DeployController.java:750) at com.caucho.server.deploy.AbstractDeployControllerStrategy.stop(AbstractDeployControllerStrategy.java:77) at com.caucho.server.deploy.DeployController.stop(DeployController.java:571) at com.caucho.server.deploy.DeployContainer.stop(DeployContainer.java:380) at com.caucho.server.webapp.WebAppContainer.stop(WebAppContainer.java:1111) at com.caucho.server.host.Host.stop(Host.java:559) at com.caucho.server.host.Host.destroy(Host.java:576) at com.caucho.server.deploy.DeployController.stopImpl(DeployController.java:750) at com.caucho.server.deploy.DeployController.restartImpl(DeployController.java:628) at com.caucho.server.deploy.StartAutoRedeployAutoStrategy.request(StartAutoRedeployAutoStrategy.java:125) at com.caucho.server.deploy.DeployController.request(DeployController.java:600) at com.caucho.server.host.HostContainer.getHost(HostContainer.java:372) at com.caucho.server.cluster.Server.getWebApp(Server.java:1084) at com.caucho.server.cluster.Server.getDefaultWebApp(Server.java:1065) at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:259) at com.caucho.server.port.TcpConnection.run(TcpConnection.java:682) at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:730) at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:649) at java.lang.Thread.run(Thread.java:619) Caused by: java.lang.NullPointerException at com.caucho.webbeans.manager.WebBeansContainer.findByName(WebBeansContainer.java:629) at com.caucho.webbeans.el.WebBeansContextResolver.getValue(WebBeansContextResolver.java:85) at com.caucho.el.StackELResolver.getValue(StackELResolver.java:143) at com.caucho.el.StackELResolver.getValue(StackELResolver.java:143) at com.caucho.el.IdExpr.getValue(IdExpr.java:100) at com.caucho.el.ArrayResolverExpr.getValue(ArrayResolverExpr.java:139) at com.caucho.el.PathExpr.getValue(PathExpr.java:142) at com.caucho.el.Expr.evalString(Expr.java:276) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:103) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.log.ELFormatter.format(ELFormatter.java:93) ... 28 more java.lang.RuntimeException: java.lang.NullPointerException at com.caucho.log.ELFormatter.format(ELFormatter.java:96) at com.caucho.log.StreamHandler.publish(StreamHandler.java:93) at com.caucho.log.SubHandler.publish(SubHandler.java:60) at com.caucho.log.EnvironmentLogger.log(EnvironmentLogger.java:329) at java.util.logging.Logger.doLog(Logger.java:494) at java.util.logging.Logger.log(Logger.java:517) at java.util.logging.Logger.finest(Logger.java:1100) at com.caucho.server.cluster.Server.clearCache(Server.java:1567) at com.caucho.server.webapp.WebAppContainer.clearCache(WebAppContainer.java:676) at com.caucho.server.host.Host.clearCache(Host.java:468) at com.caucho.server.webapp.WebApp.clearCache(WebApp.java:2140) at com.caucho.server.webapp.WebApp.destroy(WebApp.java:2802) at com.caucho.server.deploy.DeployController.stopImpl(DeployController.java:750) at com.caucho.server.deploy.AbstractDeployControllerStrategy.stop(AbstractDeployControllerStrategy.java:77) at com.caucho.server.deploy.DeployController.stop(DeployController.java:571) at com.caucho.server.deploy.DeployContainer.stop(DeployContainer.java:380) at com.caucho.server.webapp.WebAppContainer.stop(WebAppContainer.java:1111) at com.caucho.server.host.Host.stop(Host.java:559) at com.caucho.server.host.Host.destroy(Host.java:576) at com.caucho.server.deploy.DeployController.stopImpl(DeployController.java:750) at com.caucho.server.deploy.DeployController.restartImpl(DeployController.java:628) at com.caucho.server.deploy.StartAutoRedeployAutoStrategy.request(StartAutoRedeployAutoStrategy.java:125) at com.caucho.server.deploy.DeployController.request(DeployController.java:600) at com.caucho.server.host.HostContainer.getHost(HostContainer.java:372) at com.caucho.server.cluster.Server.getWebApp(Server.java:1084) at com.caucho.server.cluster.Server.getDefaultWebApp(Server.java:1065) at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:259) at com.caucho.server.port.TcpConnection.run(TcpConnection.java:682) at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:730) at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:649) at java.lang.Thread.run(Thread.java:619) Caused by: java.lang.NullPointerException at com.caucho.webbeans.manager.WebBeansContainer.findByName(WebBeansContainer.java:629) at com.caucho.webbeans.el.WebBeansContextResolver.getValue(WebBeansContextResolver.java:85) at com.caucho.el.StackELResolver.getValue(StackELResolver.java:143) at com.caucho.el.StackELResolver.getValue(StackELResolver.java:143) at com.caucho.el.IdExpr.getValue(IdExpr.java:100) at com.caucho.el.ArrayResolverExpr.getValue(ArrayResolverExpr.java:139) at com.caucho.el.PathExpr.getValue(PathExpr.java:142) at com.caucho.el.Expr.evalString(Expr.java:276) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:103) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.log.ELFormatter.format(ELFormatter.java:93) ... 30 more java.lang.RuntimeException: java.lang.NullPointerException at com.caucho.log.ELFormatter.format(ELFormatter.java:96) at com.caucho.log.StreamHandler.publish(StreamHandler.java:93) at com.caucho.log.SubHandler.publish(SubHandler.java:60) at com.caucho.log.EnvironmentLogger.log(EnvironmentLogger.java:329) at java.util.logging.Logger.doLog(Logger.java:494) at java.util.logging.Logger.log(Logger.java:517) at com.caucho.lifecycle.Lifecycle.toStop(Lifecycle.java:643) at com.caucho.server.webapp.WebApp.stop(WebApp.java:2788) at com.caucho.server.webapp.WebApp.destroy(WebApp.java:2797) at com.caucho.server.deploy.DeployController.stopImpl(DeployController.java:750) at com.caucho.server.deploy.AbstractDeployControllerStrategy.stop(AbstractDeployControllerStrategy.java:77) at com.caucho.server.deploy.DeployController.stop(DeployController.java:571) at com.caucho.server.deploy.DeployContainer.stop(DeployContainer.java:380) at com.caucho.server.webapp.WebAppContainer.stop(WebAppContainer.java:1111) at com.caucho.server.host.Host.stop(Host.java:559) at com.caucho.server.host.Host.destroy(Host.java:576) at com.caucho.server.deploy.DeployController.stopImpl(DeployController.java:750) at com.caucho.server.deploy.AbstractDeployControllerStrategy.stop(AbstractDeployControllerStrategy.java:77) at com.caucho.server.deploy.DeployController.stop(DeployController.java:571) at com.caucho.server.deploy.DeployContainer.stop(DeployContainer.java:380) at com.caucho.server.host.HostContainer.stop(HostContainer.java:495) at com.caucho.server.cluster.Server.stop(Server.java:1649) at com.caucho.server.cluster.Server.destroy(Server.java:1671) at com.caucho.server.resin.Resin.destroy(Resin.java:817) at com.caucho.server.resin.Resin$DestroyThread.run(Resin.java:1787) Caused by: java.lang.NullPointerException at com.caucho.webbeans.manager.WebBeansContainer.findByName(WebBeansContainer.java:629) at com.caucho.webbeans.el.WebBeansContextResolver.getValue(WebBeansContextResolver.java:85) at com.caucho.el.StackELResolver.getValue(StackELResolver.java:143) at com.caucho.el.StackELResolver.getValue(StackELResolver.java:143) at com.caucho.el.IdExpr.getValue(IdExpr.java:100) at com.caucho.el.ArrayResolverExpr.getValue(ArrayResolverExpr.java:139) at com.caucho.el.PathExpr.getValue(PathExpr.java:142) at com.caucho.el.Expr.evalString(Expr.java:276) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:103) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.log.ELFormatter.format(ELFormatter.java:93) ... 24 more java.lang.RuntimeException: java.lang.NullPointerException at com.caucho.log.ELFormatter.format(ELFormatter.java:96) at com.caucho.log.StreamHandler.publish(StreamHandler.java:93) at com.caucho.log.SubHandler.publish(SubHandler.java:60) at com.caucho.log.EnvironmentLogger.log(EnvironmentLogger.java:329) at java.util.logging.Logger.doLog(Logger.java:494) at java.util.logging.Logger.log(Logger.java:517) at com.caucho.lifecycle.Lifecycle.toDestroy(Lifecycle.java:698) at com.caucho.server.webapp.WebApp.destroy(WebApp.java:2799) at com.caucho.server.deploy.DeployController.stopImpl(DeployController.java:750) at com.caucho.server.deploy.AbstractDeployControllerStrategy.stop(AbstractDeployControllerStrategy.java:77) at com.caucho.server.deploy.DeployController.stop(DeployController.java:571) at com.caucho.server.deploy.DeployContainer.stop(DeployContainer.java:380) at com.caucho.server.webapp.WebAppContainer.stop(WebAppContainer.java:1111) at com.caucho.server.host.Host.stop(Host.java:559) at com.caucho.server.host.Host.destroy(Host.java:576) at com.caucho.server.deploy.DeployController.stopImpl(DeployController.java:750) at com.caucho.server.deploy.AbstractDeployControllerStrategy.stop(AbstractDeployControllerStrategy.java:77) at com.caucho.server.deploy.DeployController.stop(DeployController.java:571) at com.caucho.server.deploy.DeployContainer.stop(DeployContainer.java:380) at com.caucho.server.host.HostContainer.stop(HostContainer.java:495) at com.caucho.server.cluster.Server.stop(Server.java:1649) at com.caucho.server.cluster.Server.destroy(Server.java:1671) at com.caucho.server.resin.Resin.destroy(Resin.java:817) at com.caucho.server.resin.Resin$DestroyThread.run(Resin.java:1787) Caused by: java.lang.NullPointerException at com.caucho.webbeans.manager.WebBeansContainer.findByName(WebBeansContainer.java:629) at com.caucho.webbeans.el.WebBeansContextResolver.getValue(WebBeansContextResolver.java:85) at com.caucho.el.StackELResolver.getValue(StackELResolver.java:143) at com.caucho.el.StackELResolver.getValue(StackELResolver.java:143) at com.caucho.el.IdExpr.getValue(IdExpr.java:100) at com.caucho.el.ArrayResolverExpr.getValue(ArrayResolverExpr.java:139) at com.caucho.el.PathExpr.getValue(PathExpr.java:142) at com.caucho.el.Expr.evalString(Expr.java:276) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:103) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.el.InterpolateExpr.evalString(InterpolateExpr.java:97) at com.caucho.log.ELFormatter.format(ELFormatter.java:93) ... 23 more
Relationships
Attached Files:	test-npe-logging.war [^] (1,378 bytes) 02-09-09 13:42

Notes