CAS (15) — CAS 線上環境 Ehcache Replication 的非穩定重現錯誤 java.util.ConcurrentModificationException

Richaaaard發表於2016-12-30

CAS (15) — CAS 線上環境 Ehcache Replication 的非穩定重現錯誤

摘要

線上環境在 EhCache Replication 過程中出現 java.util.ConcurrentModificationException

2016-12-21 14:58:02,022 ERROR [net.sf.ehcache.distribution.RMISynchronousCacheReplicator] - <Exception on replication of putNotification. null. Continuing...
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7) java.util.ConcurrentModificationException

版本

tomcat版本:

tomcat-8.0.29

jdk版本:

jdk1.8.0_65

cas版本: 4.1.3

**cas4.1.3 (4.x還在開發過程中不是很穩定,迭代比較快,也會有些bug) *    cas-client-3.4.1

Ehcache版本:

ehcache-2.10.1.jar
ehcache-core-2.6.11.jar
        

內容

Stack Trace

完整堆疊錯誤資訊

14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7) 2016-12-21 14:58:02,022 ERROR [net.sf.ehcache.distribution.RMISynchronousCacheReplicator] - <Exception on replication of putNotification. null. Continuing...
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7) java.util.ConcurrentModificationException
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.util.HashMap$HashIterator.nextEntry(HashMap.java:922)
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.util.HashMap$EntryIterator.next(HashMap.java:962)
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.util.HashMap$EntryIterator.next(HashMap.java:960)
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.util.HashMap.writeObject(HashMap.java:1127)
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7)  at sun.reflect.GeneratedMethodAccessor2095.invoke(Unknown Source)
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7)  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.lang.reflect.Method.invoke(Method.java:606)
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:988)
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1495)
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431)
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177)
14:58:02,023 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1547)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1508)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1547)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1508)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1547)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.defaultWriteObject(ObjectOutputStream.java:440)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at net.sf.ehcache.Element.writeObject(Element.java:835)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at sun.reflect.GeneratedMethodAccessor2108.invoke(Unknown Source)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.lang.reflect.Method.invoke(Method.java:606)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:988)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1495)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:347)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at sun.rmi.server.UnicastRef.marshalValue(UnicastRef.java:293)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:152)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at net.sf.ehcache.distribution.RMICachePeer_Stub.put(Unknown Source)
14:58:02,024 INFO  [stdout] (http-/0.0.0.0:8443-7)  at net.sf.ehcache.distribution.RMISynchronousCacheReplicator.replicatePutNotification(RMISynchronousCacheReplicator.java:149)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at net.sf.ehcache.distribution.RMISynchronousCacheReplicator.notifyElementPut(RMISynchronousCacheReplicator.java:132)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at net.sf.ehcache.event.RegisteredEventListeners.notifyListener(RegisteredEventListeners.java:294)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at net.sf.ehcache.event.RegisteredEventListeners.invokeListener(RegisteredEventListeners.java:284)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at net.sf.ehcache.event.RegisteredEventListeners.internalNotifyElementPut(RegisteredEventListeners.java:144)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at net.sf.ehcache.event.RegisteredEventListeners.notifyElementPut(RegisteredEventListeners.java:122)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at net.sf.ehcache.Cache.notifyPutInternalListeners(Cache.java:1481)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at net.sf.ehcache.Cache.putInternal(Cache.java:1456)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at net.sf.ehcache.Cache.put(Cache.java:1383)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at net.sf.ehcache.Cache.put(Cache.java:1348)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jasig.cas.ticket.registry.EhCacheTicketRegistry.addTicket_aroundBody0(EhCacheTicketRegistry.java:103)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jasig.cas.ticket.registry.EhCacheTicketRegistry$AjcClosure1.run(EhCacheTicketRegistry.java:1)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jasig.inspektr.aspect.TraceLogAspect.traceMethod(TraceLogAspect.java:44)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jasig.cas.ticket.registry.EhCacheTicketRegistry.addTicket(EhCacheTicketRegistry.java:100)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jasig.cas.CentralAuthenticationServiceImpl.grantServiceTicket_aroundBody2(CentralAuthenticationServiceImpl.java:319)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jasig.cas.CentralAuthenticationServiceImpl$AjcClosure3.run(CentralAuthenticationServiceImpl.java:1)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jasig.inspektr.aspect.TraceLogAspect.traceMethod(TraceLogAspect.java:44)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jasig.cas.CentralAuthenticationServiceImpl.grantServiceTicket(CentralAuthenticationServiceImpl.java:241)
14:58:02,025 INFO  [stdout] (http-/0.0.0.0:8443-7)  at sun.reflect.GeneratedMethodAccessor214.invoke(Unknown Source)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.lang.reflect.Method.invoke(Method.java:606)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jasig.inspektr.audit.AuditTrailManagementAspect.handleAuditTrail(AuditTrailManagementAspect.java:128)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at sun.reflect.GeneratedMethodAccessor41.invoke(Unknown Source)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.lang.reflect.Method.invoke(Method.java:606)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:68)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at com.ryantenney.metrics.spring.MeteredMethodInterceptor.invoke(MeteredMethodInterceptor.java:45)
14:58:02,026 INFO  [stdout] (http-/0.0.0.0:8443-7)  at com.ryantenney.metrics.spring.MeteredMethodInterceptor.invoke(MeteredMethodInterceptor.java:32)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at com.ryantenney.metrics.spring.AbstractMetricMethodInterceptor.invoke(AbstractMetricMethodInterceptor.java:59)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at com.ryantenney.metrics.spring.TimedMethodInterceptor.invoke(TimedMethodInterceptor.java:48)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at com.ryantenney.metrics.spring.TimedMethodInterceptor.invoke(TimedMethodInterceptor.java:34)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at com.ryantenney.metrics.spring.AbstractMetricMethodInterceptor.invoke(AbstractMetricMethodInterceptor.java:59)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at com.sun.proxy.$Proxy57.grantServiceTicket(Unknown Source)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jasig.cas.web.flow.GenerateServiceTicketAction.doExecute(GenerateServiceTicketAction.java:57)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.action.AbstractAction.execute(AbstractAction.java:188)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.execution.ActionExecutor.execute(ActionExecutor.java:51)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.action.EvaluateAction.doExecute(EvaluateAction.java:77)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.action.AbstractAction.execute(AbstractAction.java:188)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.execution.AnnotatedAction.execute(AnnotatedAction.java:145)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.execution.ActionExecutor.execute(ActionExecutor.java:51)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.ActionState.doEnter(ActionState.java:101)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.State.enter(State.java:194)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.Transition.execute(Transition.java:228)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.DecisionState.doEnter(DecisionState.java:51)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.State.enter(State.java:194)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.Transition.execute(Transition.java:228)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.DecisionState.doEnter(DecisionState.java:51)
14:58:02,027 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.State.enter(State.java:194)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.Transition.execute(Transition.java:228)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.impl.FlowExecutionImpl.execute(FlowExecutionImpl.java:395)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.impl.RequestControlContextImpl.execute(RequestControlContextImpl.java:214)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.TransitionableState.handleEvent(TransitionableState.java:116)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.Flow.handleEvent(Flow.java:547)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.impl.FlowExecutionImpl.handleEvent(FlowExecutionImpl.java:390)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.impl.RequestControlContextImpl.handleEvent(RequestControlContextImpl.java:210)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.ActionState.doEnter(ActionState.java:105)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.State.enter(State.java:194)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.Flow.start(Flow.java:527)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.impl.FlowExecutionImpl.start(FlowExecutionImpl.java:368)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.engine.impl.FlowExecutionImpl.start(FlowExecutionImpl.java:223)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.executor.FlowExecutorImpl.launchExecution(FlowExecutorImpl.java:140)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.handle(FlowHandlerAdapter.java:238)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959)
14:58:02,028 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:967)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:858)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at javax.servlet.http.HttpServlet.service(HttpServlet.java:734)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:843)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:295)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jasig.cas.security.RequestParameterPolicyEnforcementFilter.doFilter(RequestParameterPolicyEnforcementFilter.java:250)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:246)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jasig.inspektr.common.web.ClientInfoThreadLocalFilter.doFilter(ClientInfoThreadLocalFilter.java:62)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:246)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:85)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261)
14:58:02,029 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:246)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:231)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:149)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jboss.as.jpa.interceptor.WebNonTxEmCloserValve.invoke(WebNonTxEmCloserValve.java:50)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jboss.as.jpa.interceptor.WebNonTxEmCloserValve.invoke(WebNonTxEmCloserValve.java:50)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:150)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:854)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:653)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:926)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7)  at java.lang.Thread.run(Thread.java:745)
14:58:02,030 INFO  [stdout] (http-/0.0.0.0:8443-7) >

問題排查

  1. 定位問題發生的場景

    CAS (15) — CAS 線上環境 Ehcache Replication 的非穩定重現錯誤 java.util.ConcurrentModificationException

    該錯誤出現在生成 ticket 之後往 Ehcache 中 put 相應的快取記錄。

  2. 對比當前版本(2.10.1)的 RMISynchronousCacheReplicator 與最新版本(2.10.3)的修改

    CAS (15) — CAS 線上環境 Ehcache Replication 的非穩定重現錯誤 java.util.ConcurrentModificationException

    發現官方並沒有對出現問題的類做過任何 bug 修復

  3. 懷疑是否有配置錯誤?

解決方案

根據 forums.terracotta.org 的建議,將 ehcache 的 copyOnRead 設定為 true 。

可以在 Cache Configuration: copyOnRead and copyOnWrite cache configuration 找到相應的配置示例。

<cache name="copyCache"
    maxEntriesLocalHeap="10"
    eternal="false"
    timeToIdleSeconds="5"
    timeToLiveSeconds="10"
    copyOnRead="true"
    copyOnWrite="true">
  <persistence strategy="none"/>
  <copyStrategy class="com.company.ehcache.MyCopyStrategy"/>
</cache>

在 CAS 的 ticketRegistry.xml 中對 cas_st 與 cas_tgt 進行修改。

<bean id="abstractTicketCache" abstract="true"
      class="org.springframework.cache.ehcache.EhCacheFactoryBean"
      p:cacheManager-ref="cacheManager"
      p:diskExpiryThreadIntervalSeconds="0"
      p:diskPersistent="false"
      p:eternal="false"
      p:maxElementsInMemory="50000"
      p:maxElementsOnDisk="0"
      p:memoryStoreEvictionPolicy="LRU"
      p:overflowToDisk="false"
      p:copyOnRead="true" <== 設定 copyOnRead
      p:bootstrapCacheLoader-ref="ticketCacheBootstrapCacheLoader" />

<bean id="serviceTicketsCache"
      class="org.springframework.cache.ehcache.EhCacheFactoryBean"
      parent="abstractTicketCache"
      p:cacheName="cas_st"
      p:timeToIdle="0"
      p:timeToLive="300"
      p:cacheEventListeners-ref="ticketRMISynchronousCacheReplicator" />

<bean id="ticketGrantingTicketsCache"
      class="org.springframework.cache.ehcache.EhCacheFactoryBean"
      parent="abstractTicketCache"
      p:cacheName="cas_tgt"
      p:timeToIdle="7201"
      p:timeToLive="0"
      p:cacheEventListeners-ref="ticketRMIAsynchronousCacheReplicator" />

備選應急方案

如果生產環境的叢集仍然出現此錯誤,可以通過輪流重啟不同節點的伺服器暫時解決此問題。

參考

參考來源:

CAS Protocol 3.0 Specification

Shiro Eh Cache ConcurrenctModificationException

ConcurrentModificationException when putting an ArrayList as an Element

RMI 方式 Ehcache 叢集的原始碼分析

結束

相關文章