Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

CommandGateway send command error:unit of work already CLOSED #1052

Open
darknessitachi opened this issue Apr 10, 2019 · 5 comments

Comments

Projects
None yet
3 participants
@darknessitachi
Copy link

commented Apr 10, 2019

in spring mvc controller, send a command, code like this:

commandGateway.sendAndWait(command)

when i start the tomcat, it's fine, after one or two days, all commandGateway send command not work, show exception: "cannot register a listener for phase cleanup because the unit of work is already in a later phase: CLOSED".

@abuijze

This comment has been minimized.

Copy link
Member

commented Apr 10, 2019

Which version of Axon are you observing this on?

@darknessitachi

This comment has been minimized.

Copy link
Author

commented Apr 12, 2019

I use Axon 3.4,this issuse always comming after tomcat start one or two days, i restart the server, this issuse not exist until next several days

@abuijze

This comment has been minimized.

Copy link
Member

commented Apr 12, 2019

Interesting. It's most likely caused by a ThreadLocal not being properly cleaned up. However, the Unit of Work is marked closed, so there shouldn't be a reason why it's not unregistered. Because Tomcat re-uses threads, these Thread Local registrations may also come back round when handling new requests.
The unregistration is called in a finally block by itself, so I don't see any reason why it wasn't called.
Do you see any other stacktraces related to Unit of Work?

@darknessitachi

This comment has been minimized.

Copy link
Author

commented Apr 13, 2019

 java.lang.IllegalStateException: Cannot register a listener for phase: CLEANUP because the Unit of Work is already in a later phase: CLOSED
 at org.axonframework.common.Assert.state(Assert.java:42)
 at org.axonframework.messaging.unitofwork.DefaultUnitOfWork.addHandler(DefaultUnitOfWork.java:96)
 at org.axonframework.messaging.unitofwork.AbstractUnitOfWork.onCleanup(AbstractUnitOfWork.java:193)
 at org.axonframework.messaging.unitofwork.AbstractUnitOfWork.lambda$start$3(AbstractUnitOfWork.java:55)
 at org.axonframework.messaging.unitofwork.AbstractUnitOfWork$$Lambda$312/485814789.accept(Unknown Source)
 at org.axonframework.messaging.unitofwork.CurrentUnitOfWork.ifStarted(CurrentUnitOfWork.java:57)
 at org.axonframework.messaging.unitofwork.AbstractUnitOfWork.start(AbstractUnitOfWork.java:52)
 at org.axonframework.messaging.unitofwork.DefaultUnitOfWork.startAndGet(DefaultUnitOfWork.java:48)
 at org.axonframework.commandhandling.SimpleCommandBus.handle(SimpleCommandBus.java:144)
 at org.axonframework.commandhandling.SimpleCommandBus.doDispatch(SimpleCommandBus.java:121)
 at org.axonframework.commandhandling.SimpleCommandBus.dispatch(SimpleCommandBus.java:85)
 at org.axonframework.commandhandling.gateway.AbstractCommandGateway.send(AbstractCommandGateway.java:79)
 at org.axonframework.commandhandling.gateway.DefaultCommandGateway.send(DefaultCommandGateway.java:95)
 at org.axonframework.commandhandling.gateway.DefaultCommandGateway.sendAndWait(DefaultCommandGateway.java:113)
 at com.xdreamaker.person.web.rest.PersonController.update(ClueController.java:134)
 at com.xdreamaker.person.web.rest.PersonController$$FastClassBySpringCGLIB$$b34297be.invoke()
 at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
 at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:721)
 at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
 at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
 at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282)
 at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
 at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
 at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:656)
 at com.xdreamaker.person.web.rest.PersonController$$EnhancerBySpringCGLIB$$bcf4392e.update()
 at sun.reflect.GeneratedMethodAccessor286.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke(Method.java:483)
 at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
 at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133)
 at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:116)
 at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827)
 at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738)
 at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
 at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:963)
 at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:897)
 at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
 at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:661)
 at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
 at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
 at com.rapidark.framework.core.LoginFilter.doFilter(LoginFilter.java:134)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
 at org.jasig.cas.client.authentication.AuthenticationFilter.doFilter(AuthenticationFilter.java:132)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
 at org.jasig.cas.client.validation.AbstractTicketValidationFilter.doFilter(AbstractTicketValidationFilter.java:196)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
 at org.jasig.cas.client.session.SingleSignOutFilter.doFilter(SingleSignOutFilter.java:65)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
 at com.thetransactioncompany.cors.CORSFilter.doFilter(CORSFilter.java:198)
 at com.thetransactioncompany.cors.CORSFilter.doFilter(CORSFilter.java:244)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
 at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197)
 at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
 at org.springframework.boot.web.support.ErrorPageFilter.doFilter(ErrorPageFilter.java:115)
 at org.springframework.boot.web.support.ErrorPageFilter.access$000(ErrorPageFilter.java:59)
 at org.springframework.boot.web.support.ErrorPageFilter$1.doFilterInternal(ErrorPageFilter.java:90)
 at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
 at org.springframework.boot.web.support.ErrorPageFilter.doFilter(ErrorPageFilter.java:108)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
 at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493)
 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
 at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650)
 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
 at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:800)
 at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
 at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806)
 at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498)
 at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
 at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
 at java.lang.Thread.run(Thread.java:745)
@smcvb

This comment has been minimized.

Copy link
Member

commented May 7, 2019

Thanks for the stack trace @darknessitachi, and sorry for the late reply. We've been quite busy over at AxonIQ and we've had some issue fall between the cracks...however, I am here to pick this up again.

The stack trace you've shared seems to be the problem you've noted at the top of this issue, namely that the CLEANUP phase cannot be added as the Current Unit of Work is already CLOSED.
As @abuijze alright hinted towards, this is likely because an old Unit of Work has not been cleared from the ThreadLocal.

This assumption corresponds with the situation you're in. Of a new Unit of Work is started, it'll check whether it should be nested into an already present Unit of Work. If this is the case, the CLEANUP phase will be added immediately; it's the CLEANUP phase which cant be added in your application, as it's parent Unit of Work is already CLOSED, but no clean up.

The code around the Unit of Work is set up such that in the finally blocks of the 'commit' step and the 'rollback' step will remove that Unit of Work from the ThreadLocal. It's this step which isn't occurring I assume. Likely, Tomcat is interrupting/killing a thread prior to it being completed, thus causing the ThreadLocal to not be cleaned.

So, this trails back to what @abuijze asked earlier: do you have any other stack traces suggesting a commit or rollback operation failed? This might point to something we'd be able to fix.

@smcvb smcvb self-assigned this May 7, 2019

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.