Hallo André, Christoph, Kenny,
heute war es bei uns wieder so weit.
Ich konnte dabei ein paar Logs mitschneiden und dazu habe ich auch noch einige Softwareversionen aufgeschrieben, in der Hoffnung, das hilft etwas weiter. Jeder Tipp wäre sehr hilfreich.
- Tomcat 6.0.36
- Oracle Java JDK 1.6.0.41_b02
- libapache2-mod-jk 1.2.28-2
- mysql-connector-java-5.1.23-bin.jar
Verwendete Klassen im Web-Projekt:
<firstspirit.version>4.2.488</firstspirit.version>
<firstspirit.version.prod>4.2.488</firstspirit.version.prod>
<guava.version>12.0</guava.version>
<jsf.version>1.2_15-B02</jsf.version>
<richfaces.version>3.3.3.Final</richfaces.version>
<seam.version>2.2.2.Final</seam.version>
<seam.servlet.path>/*</seam.servlet.path>
<myfaces.tomahawk.version>1.1.14</myfaces.tomahawk.version>
<mysql.version>5.1.21</mysql.version>
<junit.version>4.10</junit.version>
<testng.version>5.8</testng.version>
<jboss.embedded.version>beta3.SP10</jboss.embedded.version>
<javax.activation.version>1.1</javax.activation.version>
<slf4j.version>1.6.1</slf4j.version>
<javax.el.version>1.0</javax.el.version>
Folgendes erstes Log entstand einige Stunden vor dem Absturz. Könnte sein, dass sich Meldungen wie diese "aufstauen" und dann den Folge-Fehler verursachen:
Aug 23, 2013 6:03:54 AM org.apache.catalina.session.StandardSession expire
SEVERE: Session event listener threw exception
java.lang.IllegalStateException: Please end the HttpSession via org.jboss.seam.web.Session.instance().invalidate()
at org.jboss.seam.contexts.Lifecycle.endSession(Lifecycle.java:267)
at org.jboss.seam.contexts.ServletLifecycle.endSession(ServletLifecycle.java:187)
at org.jboss.seam.servlet.SeamListener.sessionDestroyed(SeamListener.java:59)
at org.apache.catalina.session.StandardSession.expire(StandardSession.java:720)
at org.apache.catalina.session.StandardSession.isValid(StandardSession.java:587)
at org.apache.catalina.connector.Request.doGetSession(Request.java:2406)
at org.apache.catalina.connector.Request.getSession(Request.java:2157)
at org.apache.catalina.connector.RequestFacade.getSession(RequestFacade.java:833)
at javax.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:216)
at com.sun.faces.context.SessionMap.getSession(ExternalContextImpl.java:1006)
at com.sun.faces.context.SessionMap.get(ExternalContextImpl.java:961)
at org.jboss.seam.contexts.ServerConversationContext.get(ServerConversationContext.java:110)
at org.jboss.seam.Component.getInstance(Component.java:2002)
at org.jboss.seam.Component.getInstance(Component.java:1997)
at org.jboss.seam.Component.getInstance(Component.java:1970)
at org.jboss.seam.Component.getInstance(Component.java:1965)
at org.jboss.seam.core.Conversation.instance(Conversation.java:124)
at org.jboss.seam.faces.FacesManager.prepareBackswitch(FacesManager.java:260)
at org.jboss.seam.jsf.SeamPhaseListener.beforeRenderResponse(SeamPhaseListener.java:486)
at org.jboss.seam.jsf.SeamPhaseListener.beforeServletPhase(SeamPhaseListener.java:147)
at org.jboss.seam.jsf.SeamPhaseListener.beforePhase(SeamPhaseListener.java:117)
at com.sun.faces.lifecycle.Phase.handleBeforePhase(Phase.java:214)
at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:96)
at com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:139)
at javax.faces.webapp.FacesServlet.service(FacesServlet.java:266)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.myfaces.webapp.filter.ExtensionsFilter.doFilter(ExtensionsFilter.java:374)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:83)
at org.jboss.seam.web.IdentityFilter.doFilter(IdentityFilter.java:40)
at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
at org.jboss.seam.web.MultipartFilter.doFilter(MultipartFilter.java:90)
at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
at org.jboss.seam.web.ExceptionFilter.doFilter(ExceptionFilter.java:64)
at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
at org.jboss.seam.web.RedirectFilter.doFilter(RedirectFilter.java:45)
at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
at org.ajax4jsf.webapp.BaseXMLFilter.doXmlFilter(BaseXMLFilter.java:206)
at org.ajax4jsf.webapp.BaseFilter.handleRequest(BaseFilter.java:290)
at org.ajax4jsf.webapp.BaseFilter.processUploadsAndHandleRequest(BaseFilter.java:388)
at org.ajax4jsf.webapp.BaseFilter.doFilter(BaseFilter.java:515)
at org.jboss.seam.web.Ajax4jsfFilter.doFilter(Ajax4jsfFilter.java:56)
at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
at org.jboss.seam.web.LoggingFilter.doFilter(LoggingFilter.java:60)
at org.jboss.seam.servlet.SeamFilter$FilterChainImpl.doFilter(SeamFilter.java:69)
at org.jboss.seam.servlet.SeamFilter.doFilter(SeamFilter.java:158)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:615)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:311)
at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:776)
at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:705)
at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:898)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
at java.lang.Thread.run(Thread.java:662)
Und dann habe ich diese Fehler zur Zeit des Absturzes aus dem catalina-Log extrahieren können:
Aug 28, 2013 3:29:25 PM org.apache.catalina.core.ApplicationDispatcher invoke
SEVERE: Servlet.service() for servlet Faces Servlet threw exception
org.jboss.seam.core.LockTimeoutException: could not acquire lock on @Synchronized component: profilViewHelper
at org.jboss.seam.core.SynchronizationInterceptor.aroundInvoke(SynchronizationInterceptor.java:41)
at org.jboss.seam.intercept.SeamInvocationContext.proceed(SeamInvocationContext.java:68)
at org.jboss.seam.intercept.RootInterceptor.invoke(RootInterceptor.java:107)
at org.jboss.seam.intercept.JavaBeanInterceptor.interceptInvocation(JavaBeanInterceptor.java:185)
at org.jboss.seam.intercept.JavaBeanInterceptor.invoke(JavaBeanInterceptor.java:103)
at de.softwareforen.fs.portal.viewhelper.ProfilViewHelper_$$_javassist_seam_8.setLastLoginDate(ProfilViewHelper_$$_javassist_seam_8.java)
at sun.reflect.GeneratedMethodAccessor610.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.jboss.el.util.ReflectionUtil.invokeMethod(ReflectionUtil.java:335)
at org.jboss.el.util.ReflectionUtil.invokeMethod(ReflectionUtil.java:280)
at org.jboss.el.parser.AstMethodSuffix.getValue(AstMethodSuffix.java:59)
at org.jboss.el.parser.AstValue.getValue(AstValue.java:67)
at org.jboss.el.parser.AstDeferredExpression.getValue(AstDeferredExpression.java:26)
at org.jboss.el.parser.AstCompositeExpression.getValue(AstCompositeExpression.java:31)
at org.jboss.el.ValueExpressionImpl.getValue(ValueExpressionImpl.java:186)
at com.sun.facelets.el.TagValueExpression.getValue(TagValueExpression.java:71)
at org.richfaces.component.html.HtmlModalPanel.getOnhide(HtmlModalPanel.java:596)
at sun.reflect.GeneratedMethodAccessor609.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at javax.faces.component.UIComponentBase$AttributesMap.get(UIComponentBase.java:1609)
at org.richfaces.renderkit.ModalPanelRendererBase.initializeResources(ModalPanelRendererBase.java:148)
at org.richfaces.renderkit.html.ModalPanelRenderer.doEncodeBegin(ModalPanelRenderer.java:189)
at org.richfaces.renderkit.html.ModalPanelRenderer.doEncodeBegin(ModalPanelRenderer.java:178)
at org.ajax4jsf.renderkit.RendererBase.encodeBegin(RendererBase.java:100)
at javax.faces.component.UIComponentBase.encodeBegin(UIComponentBase.java:816)
at javax.faces.component.UIComponent.encodeAll(UIComponent.java:928)
at javax.faces.component.UIComponent.encodeAll(UIComponent.java:933)
at com.sun.facelets.FaceletViewHandler.renderView(FaceletViewHandler.java:592)
at org.ajax4jsf.application.ViewHandlerWrapper.renderView(ViewHandlerWrapper.java:100)
at org.ajax4jsf.application.AjaxViewHandler.renderView(AjaxViewHandler.java:176)
at com.sun.faces.lifecycle.RenderResponsePhase.execute(RenderResponsePhase.java:110)
at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:100)
at com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:139)
at javax.faces.webapp.FacesServlet.service(FacesServlet.java:266)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:646)
at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:438)
Aug 28, 2013 3:29:25 PM org.apache.catalina.core.StandardHostValve custom
SEVERE: Exception Processing ErrorPage[errorCode=500, location=/de/system/500.xhtml]
javax.servlet.ServletException: javax.el.ELException: /de/fragmente/basic_modalpanel.xhtml @21,60 onhide="document.location.reload(true);#{profilViewHelper.setLastLoginDate()}": org.jboss.seam.core.LockTimeoutException: could not acquire lock on @Synchronized component: profilViewHelper
at javax.faces.webapp.FacesServlet.service(FacesServlet.java:277)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:646)
at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:438)
at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:374)
at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:302)
at org.apache.catalina.core.StandardHostValve.custom(StandardHostValve.java:421)
at org.apache.catalina.core.StandardHostValve.status(StandardHostValve.java:342)
at org.apache.catalina.core.StandardHostValve.throwable(StandardHostValve.java:286)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:615)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:311)
at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:776)
at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:705)
at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:898)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
at java.lang.Thread.run(Thread.java:662)
15:30:00,440 WARN [ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@71f670d8 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
15:30:43,068 WARN [ThreadPoolAsynchronousRunner] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@71f670d8 -- APPARENT DEADLOCK!!! Complete Status:
Managed Threads: 3
Active Threads: 3
Active Tasks:
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@5a5dd88c (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2)
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@4733fdad (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0)
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@26538d60 (com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1)
Pending Tasks:
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@3766ad48
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@35fa6e62
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@4c64ff9d
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@7ac9c399
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@5448b0c9
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@704e8759
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@33981da9
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@47c35cb5
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@6afb93e1
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@2aa9cfa6
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@727fb12b
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@1d48b8c7
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@115b1fd6
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@75872380
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@7b2be4c7
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@7eb903fd
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@24b5180a
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@6d3d4b59
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@531df816
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@548a96fb
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@56be6419
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@6d9dd1cc
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@1438e04d
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@220de99a
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@3f638eed
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@213c8a1e
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@d8fc89e
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@5abc0406
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@6dac5473
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@4cdc8245
com.mchange.v2.resourcepool.BasicResourcePool$1RefurbishCheckinResourceTask@20eca76f
Pool thread stack traces:
Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2,5,main]
com.mchange.v2.resourcepool.BasicResourcePool.setLastAcquisitionFailure(BasicResourcePool.java:194)
com.mchange.v2.resourcepool.BasicResourcePool.access$1000(BasicResourcePool.java:32)
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1834)
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0,5,main]
com.mchange.v2.resourcepool.BasicResourcePool.setLastAcquisitionFailure(BasicResourcePool.java:194)
com.mchange.v2.resourcepool.BasicResourcePool.access$1000(BasicResourcePool.java:32)
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1834)
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1,5,main]
com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1026)
com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32)
com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810)
com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
15:30:43,268 INFO [ProfilViewHelper] LoginDate changed
15:32:10,805 INFO [ProfilViewHelper] Try save login date from user: Wed Aug 28 15:32:10 CEST 2013
15:32:10,859 INFO [DBConnectionManager] connection leased (new created): 57eae7ac, PoolSize: 1
15:32:10,871 WARN [ThreadPoolAsynchronousRunner] Task com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@5a5dd88c (in deadlocked PoolThread) failed to complete in maximum time 60000ms. Trying interrupt().
15:32:10,874 WARN [ThreadPoolAsynchronousRunner] Task com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask@4733fdad (in deadlocked PoolThread) failed to complete in maximum time 60000ms. Trying interrupt().
15:32:56,467 INFO [ProfilViewHelper] LoginDate changed
15:32:56,515 WARN [DBConnectionManager] Retry (counter: 1) to create a new connection due to com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure
The last packet successfully received from the server was 29 milliseconds ago. The last packet sent successfully to the server was 29 milliseconds ago., PoolSize: -1
15:32:56,516 INFO [ProfilViewHelper] Try save login date from user: Wed Aug 28 15:32:56 CEST 2013