[jboss-user] [JBossCache] - Re: Unexpected (?) TimeoutException

[jacek187]

Hi
When i change to put/remove from TreeCache API I got .. different results
Sometimes I got success.
Sometimes I got NodeNotExistException - probably bug
Sometimes I got ... infinitive loop. This is critical bug !!!!!! And this situation was observer in our production systems but until now I can;t prepare JUnit test to show this case.

main loop looks now like:

  | 				for (int x = 0; x < 1000; x++) {
  | 					tm.begin();
  | 					System.out.println("R" + Thread.currentThread().getName());
  | 					//inside transaction
  | 					cache.remove("/a");
  | 					System.out.println("AR" + Thread.currentThread().getName());
  | 					tm.commit();
  | 					//outside transaction
  | 					System.out.println("P" + Thread.currentThread().getName());
  | 					cache.put("/a/b/c/d", "text"+x,"b");
  | 					System.out.println("AP" + Thread.currentThread().getName());
  | 				}
  | 

The most critical bug is infinitive loop - sometimes this test never ends, CPU usage is 100%, and ThreadDumps shows, that one thread is still working in loop:
PessimisticLockInterceptor, lines 173-178


  |             do
  |             {
  |                lock(fqn, ctx.getGlobalTransaction(), lock_type, recursive, zeroLockTimeout ? 0 : lock_timeout, createIfNotExists, storeLockedNode);
  |             }
  |             while(!cache.exists(fqn)); // keep trying until we have the lock (fixes concurrent remove())
  | 



Some thread dumps

Dump 1:

"Thread:0" prio=6 tid=0x0ae49c48 nid=0x121c runnable [0x0b38f000..0x0b38fb68]
	at org.jboss.cache.interceptors.PessimisticLockInterceptor.recordNodeLock(PessimisticLockInterceptor.java:398)
	at org.jboss.cache.interceptors.PessimisticLockInterceptor.acquireNodeLock(PessimisticLockInterceptor.java:383)
	at org.jboss.cache.interceptors.PessimisticLockInterceptor.lock(PessimisticLockInterceptor.java:307)
	at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:175)
	at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
	at org.jboss.cache.interceptors.UnlockInterceptor.invoke(UnlockInterceptor.java:32)
	at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
	at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:365)
	at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:160)
	at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
	at org.jboss.cache.interceptors.CacheMgmtInterceptor.invoke(CacheMgmtInterceptor.java:157)
	at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:5877)
	at org.jboss.cache.TreeCache.put(TreeCache.java:3847)
	at org.jboss.cache.TreeCache.put(TreeCache.java:3788)
	at org.jboss.cache.aop.ConcurentPutRemoveTest$SeparateThread.run(ConcurentPutRemoveTest.java:82)



"main" prio=6 tid=0x003a7988 nid=0xbc0 in Object.wait() [0x0006f000..0x0006fc08]
	at java.lang.Object.wait(Native Method)
	- waiting on <0x02b50188> (a org.jboss.cache.aop.ConcurentPutRemoveTest$SeparateThread)
	at java.lang.Thread.join(Unknown Source)
	- locked <0x02b50188> (a org.jboss.cache.aop.ConcurentPutRemoveTest$SeparateThread)
	at java.lang.Thread.join(Unknown Source)
	at org.jboss.cache.aop.ConcurentPutRemoveTest.testLock(ConcurentPutRemoveTest.java:49)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at junit.framework.TestCase.runTest(TestCase.java:154)
	at junit.framework.TestCase.runBare(TestCase.java:127)
	at junit.framework.TestResult$1.protect(TestResult.java:106)
	at junit.framework.TestResult.runProtected(TestResult.java:124)
	at junit.framework.TestResult.run(TestResult.java:109)
	at junit.framework.TestCase.run(TestCase.java:118)
	at junit.framework.TestSuite.runTest(TestSuite.java:208)
	at junit.framework.TestSuite.run(TestSuite.java:203)
	at org.eclipse.jdt.internal.junit.runner.junit3.JUnit3TestReference.run(JUnit3TestReference.java:128)
	at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:460)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:673)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:386)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)



Dump 2 (makes 1 minute later)
"Thread:0" prio=6 tid=0x0ae49c48 nid=0x121c runnable [0x0b38f000..0x0b38fb68]
	at org.jboss.cache.Node.isMarkedForRemoval(Node.java:690)
	at org.jboss.cache.TreeCache.findInternal(TreeCache.java:3714)
	at org.jboss.cache.TreeCache.exists(TreeCache.java:3694)
	at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:177)
	at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
	at org.jboss.cache.interceptors.UnlockInterceptor.invoke(UnlockInterceptor.java:32)
	at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
	at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:365)
	at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:160)
	at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
	at org.jboss.cache.interceptors.CacheMgmtInterceptor.invoke(CacheMgmtInterceptor.java:157)
	at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:5877)
	at org.jboss.cache.TreeCache.put(TreeCache.java:3847)
	at org.jboss.cache.TreeCache.put(TreeCache.java:3788)
	at org.jboss.cache.aop.ConcurentPutRemoveTest$SeparateThread.run(ConcurentPutRemoveTest.java:82)




Dumps shows that Thread 'Thread0' is now in endless looop.......



Could anybody reproduce this error?

View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4075105#4075105

Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4075105