Hi,
we maybe got a corrupt scheduler after running activemq
under high load a while.
The symptom is:
0) ls -l scheduler/
total 181652
-rw-r--r-- 1 root root 33554516 2012-11-01 20:20 db-1.log
-rw-r--r-- 1 root root 33554677 2012-11-02 13:24 db-2.log
-rw-r--r-- 1 root root 33554541 2012-11-02 19:27 db-3.log
-rw-r--r-- 1 root root 33554496 2012-11-05 04:31 db-4.log
-rw-r--r-- 1 root root 33554992 2012-11-05 12:22 db-5.log
-rw-r--r-- 1 root root 33030144 2012-11-05 14:27 db-6.log
-rw-r--r-- 1 root root 0 2012-11-01 14:21 lock
-rw-r--r-- 1 root root 7303168 2012-11-05 14:27 scheduleDB.data
-rw-r--r-- 1 root root 102592 2012-11-05 14:27 scheduleDB.redo
1) Start activemq
2) Open http://<broker>:8161/admin/scheduled.jsp
3) The Browser gives an error-page:
Error!
Exception occurred while processing this request, check
the log for more information!
3) In activemq.log we can see:
=======================================================
2012-11-05 14:21:56,575 | WARN | /admin/scheduled.jsp |
org.eclipse.jetty.servlet.ServletHandler | qtp860405149-193781
javax.el.ELException:
javax.management.openmbean.KeyAlreadyExistsException: Argument value's
index, calculated according to this TabularData instance's tabularType,
already refers to a value in this table.
at javax.el.BeanELResolver.getValue(BeanELResolver.java:298)
at
javax.el.CompositeELResolver.getValue(CompositeELResolver.java:175)
at com.sun.el.parser.AstValue.getValue(AstValue.java:138)
at
com.sun.el.ValueExpressionImpl.getValue(ValueExpressionImpl.java:206)
at
org.apache.jasper.runtime.PageContextImpl.evaluateExpression(PageContextImpl.java:1001)
at
org.apache.jsp.scheduled_jsp._jspx_meth_c_forEach_0(org.apache.jsp.scheduled_jsp:189)
at
org.apache.jsp.scheduled_jsp._jspx_meth_c_when_0(org.apache.jsp.scheduled_jsp:163)
at
org.apache.jsp.scheduled_jsp._jspx_meth_c_choose_0(org.apache.jsp.scheduled_jsp:115)
at
org.apache.jsp.scheduled_jsp._jspService(org.apache.jsp.scheduled_jsp:84)
at
org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:109)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:806)
at
org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:389)
at
org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:486)
at
org.apache.jasper.servlet.JspServlet.service(JspServlet.java:380)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:806)
at
org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:652)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1329)
at
org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:83)
at
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1300)
at
org.apache.activemq.web.SessionFilter.doFilter(SessionFilter.java:45)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1300)
at
org.apache.activemq.web.filter.ApplicationContextFilter.doFilter(ApplicationContextFilter.java:96)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1300)
at
com.opensymphony.sitemesh.webapp.SiteMeshFilter.obtainContent(SiteMeshFilter.java:129)
at
com.opensymphony.sitemesh.webapp.SiteMeshFilter.doFilter(SiteMeshFilter.java:77)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1300)
at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:445)
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
at
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:521)
at
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:227)
at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1038)
at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:374)
at
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:189)
at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:972)
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
at
org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:154)
at
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:521)
at
org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:154)
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
at org.eclipse.jetty.server.Server.handle(Server.java:363)
at
org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:483)
at
org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:920)
at
org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:982)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:635)
at
org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
at
org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
at
org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:627)
at
org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:51)
at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
at java.lang.Thread.run(Thread.java:662)
Caused by: javax.management.openmbean.KeyAlreadyExistsException:
Argument value's index, calculated according to this TabularData
instance's tabularType, already refers to a value in this table.
at
javax.management.openmbean.TabularDataSupport.checkValueAndIndex(TabularDataSupport.java:871)
at
javax.management.openmbean.TabularDataSupport.internalPut(TabularDataSupport.java:331)
at
javax.management.openmbean.TabularDataSupport.put(TabularDataSupport.java:323)
at
org.apache.activemq.broker.jmx.JobSchedulerView.getAllJobs(JobSchedulerView.java:46)
at sun.reflect.GeneratedMethodAccessor120.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:93)
at
com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(StandardMBeanIntrospector.java:27)
at
com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:208)
at
com.sun.jmx.mbeanserver.PerInterface.getAttribute(PerInterface.java:65)
at
com.sun.jmx.mbeanserver.MBeanSupport.getAttribute(MBeanSupport.java:216)
at
javax.management.StandardMBean.getAttribute(StandardMBean.java:358)
at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getAttribute(DefaultMBeanServerInterceptor.java:666)
at
com.sun.jmx.mbeanserver.JmxMBeanServer.getAttribute(JmxMBeanServer.java:638)
at
javax.management.MBeanServerInvocationHandler.invoke(MBeanServerInvocationHandler.java:263)
at $Proxy5.getAllJobs(Unknown Source)
at
org.apache.activemq.web.BrokerFacadeSupport.getScheduledJobs(BrokerFacadeSupport.java:211)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at javax.el.BeanELResolver.getValue(BeanELResolver.java:293)
... 51 more
=======================================================
In practice the scheduler *is* still working - we can see it
firing up jobs after the timer is expired. Is there a way to
"recover" this KeyAlreadyExistsException?
Should we wait for: https://issues.apache.org/jira/browse/AMQ-3758
Greetings,
Martin
