Description:
An upgrade from 3.0.7 to 3.0.8 and a subsequent restart leaves me with the ps output below.
Basically the restart mechanism is not sufficiently good to ensure that java is not restarted cleanly prior to killing any previously running copy of MEM's tomcat processes.
How to repeat:
[root@tomcat-server ~]# ps auwx | grep java
mysqlmem 24552 277 9.4 27266660 9406924 ? Sl 16:22 233:27 jsvc.exec -java-home /opt/mysql/enterprise/monitor/java -user mysqlmem -pidfile /opt/mysql/enterprise/monitor/apache-tomcat/temp/catalina.pid -wait 10 -outfile /opt/mysql/enterprise/monitor/apache-tomcat/logs/catalina-daemon.out -errfile &1 -classpath /opt/mysql/enterprise/monitor/apache-tomcat/bin/bootstrap.jar:/opt/mysql/enterprise/monitor/apache-tomcat/bin/commons-daemon.jar:/opt/mysql/enterprise/monitor/apache-tomcat/bin/tomcat-juli.jar -Dnop -Xmx12g -Xms8g -XX:+UseBiasedLocking -XX:+UseParallelGC -XX:MaxPermSize=512m -Dxwork.profile.activate=true -Xloggc:gc_sjm.log -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -verbose:gc -XX:HeapDumpPath=/tmp -server -Dxwork.profile.activate=true -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.endorsed.dirs= -Dcatalina.base=/opt/mysql/enterprise/monitor/apache-tomcat -Dcatalina.home=/opt/mysql/enterprise/monitor/apache-tomcat -Djava.io.tmpdir=/opt/mysql/enterprise/monitor/apache-tomcat/temp org.apache.catalina.startup.Bootstrap
root 24834 0.0 0.0 10432 380 ? Ss 16:42 0:00 jsvc.exec -java-home /opt/mysql/enterprise/monitor/java -user mysqlmem -pidfile /opt/mysql/enterprise/monitor/apache-tomcat/temp/catalina.pid -wait 10 -outfile /opt/mysql/enterprise/monitor/apache-tomcat/logs/catalina-daemon.out -errfile &1 -classpath /opt/mysql/enterprise/monitor/apache-tomcat/bin/bootstrap.jar:/opt/mysql/enterprise/monitor/apache-tomcat/bin/commons-daemon.jar:/opt/mysql/enterprise/monitor/apache-tomcat/bin/tomcat-juli.jar -Dnop -Xmx12g -Xms8g -XX:+UseBiasedLocking -XX:+UseParallelGC -XX:MaxPermSize=512m -Dxwork.profile.activate=true -Xloggc:gc_sjm.log -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -verbose:gc -XX:HeapDumpPath=/tmp -server -Dxwork.profile.activate=true -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.endorsed.dirs= -Dcatalina.base=/opt/mysql/enterprise/monitor/apache-tomcat -Dcatalina.home=/opt/mysql/enterprise/monitor/apache-tomcat -Djava.io.tmpdir=/opt/mysql/enterprise/monitor/apache-tomcat/temp org.apache.catalina.startup.Bootstrap
mysqlmem 24835 7.6 3.1 20263932 3158244 ? Sl 16:42 4:51 jsvc.exec -java-home /opt/mysql/enterprise/monitor/java -user mysqlmem -pidfile /opt/mysql/enterprise/monitor/apache-tomcat/temp/catalina.pid -wait 10 -outfile /opt/mysql/enterprise/monitor/apache-tomcat/logs/catalina-daemon.out -errfile &1 -classpath /opt/mysql/enterprise/monitor/apache-tomcat/bin/bootstrap.jar:/opt/mysql/enterprise/monitor/apache-tomcat/bin/commons-daemon.jar:/opt/mysql/enterprise/monitor/apache-tomcat/bin/tomcat-juli.jar -Dnop -Xmx12g -Xms8g -XX:+UseBiasedLocking -XX:+UseParallelGC -XX:MaxPermSize=512m -Dxwork.profile.activate=true -Xloggc:gc_sjm.log -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -verbose:gc -XX:HeapDumpPath=/tmp -server -Dxwork.profile.activate=true -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.endorsed.dirs= -Dcatalina.base=/opt/mysql/enterprise/monitor/apache-tomcat -Dcatalina.home=/opt/mysql/enterprise/monitor/apache-tomcat -Djava.io.tmpdir=/opt/mysql/enterprise/monitor/apache-tomcat/temp org.apache.catalina.startup.Bootstrap
root 26941 0.0 0.0 10432 440 ? Ss Apr03 0:00 jsvc.exec -java-home /opt/mysql/enterprise/monitor/java -user mysqlmem -pidfile /opt/mysql/enterprise/monitor/apache-tomcat/temp/catalina.pid -wait 10 -outfile /opt/mysql/enterprise/monitor/apache-tomcat/logs/catalina-daemon.out -errfile &1 -classpath /opt/mysql/enterprise/monitor/apache-tomcat/bin/bootstrap.jar:/opt/mysql/enterprise/monitor/apache-tomcat/bin/commons-daemon.jar:/opt/mysql/enterprise/monitor/apache-tomcat/bin/tomcat-juli.jar -Dnop -Xmx12g -Xms8g -XX:+UseBiasedLocking -XX:+UseParallelGC -XX:MaxPermSize=512m -Dxwork.profile.activate=true -Xloggc:gc_sjm.log -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -verbose:gc -XX:HeapDumpPath=/tmp -server -Dxwork.profile.activate=true -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.endorsed.dirs= -Dcatalina.base=/opt/mysql/enterprise/monitor/apache-tomcat -Dcatalina.home=/opt/mysql/enterprise/monitor/apache-tomcat -Djava.io.tmpdir=/opt/mysql/enterprise/monitor/apache-tomcat/temp org.apache.catalina.startup.Bootstrap
root 28404 0.0 0.0 103240 880 pts/1 S+ 17:46 0:00 grep java
A stack trace of a failed login attempt with this messed up setup is shown below:
HTTP Status 500 - javax.servlet.ServletException: Unable to instantiate Action, com.mysql.merlin.ui.actions.DoAuth, defined for 'DoAuth' in namespace '/'null
type Exception report
message javax.servlet.ServletException: Unable to instantiate Action, com.mysql.merlin.ui.actions.DoAuth, defined for 'DoAuth' in namespace '/'null
description The server encountered an internal error that prevented it from fulfilling this request.
exception
javax.servlet.ServletException: javax.servlet.ServletException: Unable to instantiate Action, com.mysql.merlin.ui.actions.DoAuth, defined for 'DoAuth' in namespace '/'null
net.sf.ehcache.constructs.web.filter.Filter.logThrowable(Filter.java:143)
net.sf.ehcache.constructs.web.filter.Filter.doFilter(Filter.java:91)
com.mysql.merlin.ui.filters.MimeSniffHeaderFilter.doFilter(MimeSniffHeaderFilter.java:30)
com.mysql.merlin.ui.filters.XFrameOptionsHeaderFilter.doFilter(XFrameOptionsHeaderFilter.java:30)
com.mysql.merlin.ui.filters.UiActionMarkerFilter.doFilter(UiActionMarkerFilter.java:50)
com.mysql.merlin.ui.filters.InventoryNamingSessionFilter.doFilter(InventoryNamingSessionFilter.java:34)
com.mysql.merlin.server.RequestCounterFilter.doFilter(RequestCounterFilter.java:99)
com.mysql.merlin.ui.filters.UnauthorizedUserExceptionCatchFilter.doFilter(UnauthorizedUserExceptionCatchFilter.java:43)
com.mysql.merlin.ui.filters.AccessLogFilter.doFilter(AccessLogFilter.java:56)
root cause
javax.servlet.ServletException: Unable to instantiate Action, com.mysql.merlin.ui.actions.DoAuth, defined for 'DoAuth' in namespace '/'null
org.apache.struts2.dispatcher.Dispatcher.serviceAction(Dispatcher.java:588)
org.apache.struts2.dispatcher.ng.ExecuteOperations.executeAction(ExecuteOperations.java:77)
org.apache.struts2.dispatcher.ng.filter.StrutsPrepareAndExecuteFilter.doFilter(StrutsPrepareAndExecuteFilter.java:99)
net.sf.ehcache.constructs.web.filter.GzipFilter.doFilter(GzipFilter.java:85)
net.sf.ehcache.constructs.web.filter.Filter.doFilter(Filter.java:86)
com.mysql.merlin.ui.filters.MimeSniffHeaderFilter.doFilter(MimeSniffHeaderFilter.java:30)
com.mysql.merlin.ui.filters.XFrameOptionsHeaderFilter.doFilter(XFrameOptionsHeaderFilter.java:30)
com.mysql.merlin.ui.filters.UiActionMarkerFilter.doFilter(UiActionMarkerFilter.java:50)
com.mysql.merlin.ui.filters.InventoryNamingSessionFilter.doFilter(InventoryNamingSessionFilter.java:34)
com.mysql.merlin.server.RequestCounterFilter.doFilter(RequestCounterFilter.java:99)
com.mysql.merlin.ui.filters.UnauthorizedUserExceptionCatchFilter.doFilter(UnauthorizedUserExceptionCatchFilter.java:43)
com.mysql.merlin.ui.filters.AccessLogFilter.doFilter(AccessLogFilter.java:56)
root cause
Unable to instantiate Action, com.mysql.merlin.ui.actions.DoAuth, defined for 'DoAuth' in namespace '/'null
com.opensymphony.xwork2.DefaultActionInvocation.createAction(DefaultActionInvocation.java:316)
com.opensymphony.xwork2.DefaultActionInvocation.init(DefaultActionInvocation.java:397)
com.opensymphony.xwork2.DefaultActionProxy.prepare(DefaultActionProxy.java:194)
org.apache.struts2.impl.StrutsActionProxy.prepare(StrutsActionProxy.java:63)
org.apache.struts2.impl.StrutsActionProxyFactory.createActionProxy(StrutsActionProxyFactory.java:39)
com.opensymphony.xwork2.DefaultActionProxyFactory.createActionProxy(DefaultActionProxyFactory.java:58)
org.apache.struts2.dispatcher.Dispatcher.serviceAction(Dispatcher.java:553)
org.apache.struts2.dispatcher.ng.ExecuteOperations.executeAction(ExecuteOperations.java:77)
org.apache.struts2.dispatcher.ng.filter.StrutsPrepareAndExecuteFilter.doFilter(StrutsPrepareAndExecuteFilter.java:99)
net.sf.ehcache.constructs.web.filter.GzipFilter.doFilter(GzipFilter.java:85)
net.sf.ehcache.constructs.web.filter.Filter.doFilter(Filter.java:86)
com.mysql.merlin.ui.filters.MimeSniffHeaderFilter.doFilter(MimeSniffHeaderFilter.java:30)
com.mysql.merlin.ui.filters.XFrameOptionsHeaderFilter.doFilter(XFrameOptionsHeaderFilter.java:30)
com.mysql.merlin.ui.filters.UiActionMarkerFilter.doFilter(UiActionMarkerFilter.java:50)
com.mysql.merlin.ui.filters.InventoryNamingSessionFilter.doFilter(InventoryNamingSessionFilter.java:34)
com.mysql.merlin.server.RequestCounterFilter.doFilter(RequestCounterFilter.java:99)
com.mysql.merlin.ui.filters.UnauthorizedUserExceptionCatchFilter.doFilter(UnauthorizedUserExceptionCatchFilter.java:43)
com.mysql.merlin.ui.filters.AccessLogFilter.doFilter(AccessLogFilter.java:56)
root cause
java.lang.NullPointerException
note The full stack trace of the root cause is available in the Apache Tomcat/7.0.41 logs.
Apache Tomcat/7.0.41
Suggested fix:
It should not be possible for tomcat to stay up if an existing running process is up and bound to the network ports where MEM listens for connections. If MEM is unable to bind to these ports then this should be a fatal error and all of tomcat should shutdown. This doesn't seem to happen now. Perhaps related to the tomcat architecture but ideally the whole java process should stop.
When multiple processes are running with the same configuration things don't work properly, so this needs to be addressed.
So please make the MEM tomcat restart process more resilient, expect the shutdown to take a while, or if needed just kill -9 the processes (....) to speed things up, if it takes too long.
Note: this restart issue is also important for the upgrade process.
