AnsweredAssumed Answered

Stuck at SpringTransactionInterceptor execute !

Question asked by ssun on Jun 12, 2014
Latest reply on Jun 30, 2014 by trademak
This is a bit of long story so please bear with me for a minute:

We are using mysql database as the backend.
We are using the out of the box activiti-explorer.war and activiti-rest.war
We put them in an apache tomcat instance and we modified db.property and pointed them to the mysql database.
For the explorer we use LDAP for authentication.
We log on through the explorer and deploy our workflow definitions using the UI.
For the rest api, we do not user LDAP but created a username + password.
We have this set of username + password in our code and our code use the REST api to start process instances, complete tasks, etc.
Most of our workflows does not do the heavy lifting work. They simply sit there and the other piece of code we have will tell workflow what happened. The workflows have timers and if task did not finish in time, they will send alert emails.

After running happily for several days, we suddenly cannot login through the explorer.
The rest API has no problem at all and no performance problem.
Absolutely nothing changed during that time except we accumulated some processes and tasks (about 8000).

At first, I thought this is a problem with the explorer, so I posted this http://forums.activiti.org/content/cannot-log-after-engine-ran-few-days.
But after so many hours of trying different things, I believe this is likely very related to the engine itself so I'm moving the question here.

Here are my findings:

1. We can see the login screen with no problem but after type in username and password, it stuck and never return.
2. There are no logs at all in the apache. Basically a thread went working and never returned.
3. If I use the rest API to close all the tasks, then if I restart the server, I can log in. If I do not restart the server, I cannot.
4. I do not have to close all the tasks. I can close some of them and restart and works. I cannot tell if there are particular tasks problematic. I would hope the service be more resilient.
5. I also tested with switched the backend database back and forth with a previous working snapshot of the database. It works every time, so it is related to the data.
6. Something is wrong from the beginning when the activiti-explorer app starts. Once it is started I cannot stop the service properly using apache's script. I have to use "kill -9". Some threads are stuck from the beginning.
7. I started to spend hours compile activiti from source code and try to add loggings to try to figure out the problem. I found the problematic line is:

https://github.com/Activiti/Activiti/blob/master/modules/activiti-spring/src/main/java/org/activiti/spring/SpringTransactionInterceptor.java#L45

I added some print statements:
<blockcode>
    System.out.println("ssun: SpringTransactionInterceptor execute 4");
   
    T result = transactionTemplate.execute(new TransactionCallback<T>() {
      public T doInTransaction(TransactionStatus status) {
         System.out.println("ssun: TransactionCallback doInTransaction 1");
        T result = next.execute(config, command);
        System.out.println("ssun: TransactionCallback doInTransaction 2");
        return result;
      }
    });
    System.out.println("ssun: SpringTransactionInterceptor execute 5");
</blockcode>

And when I use the working database, I see:
ssun: SpringTransactionInterceptor execute 1
ssun: SpringTransactionInterceptor execute 2
ssun: SpringTransactionInterceptor execute 3
ssun: SpringTransactionInterceptor execute 4
ssun: TransactionCallback doInTransaction 1
ssun: TransactionCallback doInTransaction 2
ssun: SpringTransactionInterceptor execute 5

When I use the non-working database, I see:
ssun: SpringTransactionInterceptor execute 1
ssun: SpringTransactionInterceptor execute 2
ssun: SpringTransactionInterceptor execute 3
ssun: SpringTransactionInterceptor execute 4

It's clearly stuck here. But from there, it is spring code. I really don't know what can I do. How can my data in my database impact how the code?
And I do not only see this when I try to login from the explorer, I see them during start up which confirms my feeling that some threads got stuck from the beginning.

Also here is the stack trace I printed out at the stucking point when I try to login:

ssun: authenticate 1
ssun: checkPassword 1
ssun: CommandExecutorImpl.execute 1
class org.activiti.engine.impl.interceptor.LogInterceptor
ssun: LogInterceptor.execute 1
ssun: LogInterceptor.execute 2
class org.activiti.spring.SpringTransactionInterceptor
ssun: SpringTransactionInterceptor execute 1
ssun: SpringTransactionInterceptor execute 2
ssun: SpringTransactionInterceptor execute 3
ssun: SpringTransactionInterceptor execute 4
java.lang.RuntimeException
   at org.activiti.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:48)
   at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:34)
   at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:43)
   at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:35)
   at org.activiti.engine.impl.IdentityServiceImpl.checkPassword(IdentityServiceImpl.java:100)
   at org.activiti.explorer.ui.login.DefaultLoginHandler.authenticate(DefaultLoginHandler.java:42)
   at org.activiti.explorer.ui.login.DefaultLoginHandler.authenticate(DefaultLoginHandler.java:35)
   at org.activiti.explorer.ui.login.LoginPage$ActivitiLoginListener.onLogin(LoginPage.java:99)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:606)
   at com.vaadin.event.ListenerMethod.receiveEvent(ListenerMethod.java:510)
   at com.vaadin.event.EventRouter.fireEvent(EventRouter.java:164)
   at com.vaadin.ui.AbstractComponent.fireEvent(AbstractComponent.java:1219)
   at com.vaadin.ui.LoginForm$2.handleParameters(LoginForm.java:103)
   at com.vaadin.ui.Window.handleParameters(Window.java:515)
   at com.vaadin.terminal.gwt.server.AbstractApplicationServlet.service(AbstractApplicationServlet.java:528)
   at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
   at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
   at org.activiti.explorer.filter.ExplorerFilter.doFilter(ExplorerFilter.java:44)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
   at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
   at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
   at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:501)
   at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
   at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:98)
   at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
   at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
   at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
   at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1040)
   at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607)
   at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:315)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   at java.lang.Thread.run(Thread.java:744)


Any thoughts would help! Thank you in advance!


Outcomes