[jboss-user] [JBoss Cache: Core Edition] - Re: Far cache problem (3.0.2) tx problems
rs1050
do-not-reply at jboss.com
Mon Feb 2 20:29:47 EST 2009
my previous post and this one uses resin and 3.0.3 snapshot.
20:22:31,403 [http--8080-1$21578710] INFO UserManagerImpl:updateUser:58 - user TX before start of TX: UserTransactionProxy[], status: 6
20:22:31,404 [http--8080-1$21578710] INFO UserManagerImpl:updateUser:63 - started user TX: UserTransactionProxy[], status: 0
20:22:31,404 [http--8080-1$21578710] DEBUG NearCacheImpl:setValue:53 - setting value for object:/user/1:86 in cacheId:3
20:22:31,405 [http--8080-1$21578710] TRACE ComponentRegistry:invocationsAllowed:877 - Testing if invocations are allowed.
20:22:31,406 [http--8080-1$21578710] TRACE InvocationContextInterceptor:handleAll:141 - Invoked with command GetNodeCommand{fqn=/user/1:86} and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false}, originLocal=true}]
20:22:31,416 [http--8080-1$21578710] TRACE InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional context.
20:22:31,417 [http--8080-1$21578710] TRACE InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as Transaction[01:916b5f76] and gtx as null
20:22:31,418 [http--8080-1$21578710] TRACE TxInterceptor:attachGlobalTransaction:446 - local transaction exists - registering global tx if not present for Thread[http--8080-1$21578710,5,main]
20:22:31,419 [http--8080-1$21578710] TRACE TxInterceptor:attachGlobalTransaction:451 - Associated gtx in txTable is null
20:22:31,443 [http--8080-1$21578710] TRACE TransactionTable:getCurrentTransaction:450 - created new GTX: GlobalTransaction::2, local TX=Transaction[01:916b5f76]
20:22:31,444 [http--8080-1$21578710] TRACE TxInterceptor:registerTransaction:719 - Registering sync handler for tx Transaction[01:916b5f76], gtx GlobalTransaction::2
20:22:31,444 [http--8080-1$21578710] TRACE TxInterceptor:registerHandler:744 - registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction::2, tx=com.caucho.transaction.TransactionImpl at 20565916))
20:22:31,459 [http--8080-1$21578710] INFO TMCacheListener:onNodeTransactionregistered:29 - : EventImpl{type=TRANSACTION_REGISTERED,pre=false, cache=org.jboss.cache.DataContainerImpl [2 nodes, 0 locks], modificationType=null, data=null, fqn=null, transaction=Transaction[01:916b5f76], originLocal=true, targetFqn=null, successful=false, newView=null, buddyGroup=null}
20:22:31,464 [http--8080-1$21578710] TRACE MVCCNodeHelper:wrapNodeForReading:136 - Node /user/1:86 is not in context, fetching from container.
20:22:31,470 [http--8080-1$21578710] TRACE CacheLoaderInterceptor:mustLoad:438 - Don't load [/user/1:86], key requested is null
20:22:31,471 [http--8080-1$21578710] TRACE CacheLoaderInterceptor:loadIfNeeded:293 - load element /user/1:86 mustLoad=false
20:22:31,472 [http--8080-1$21578710] TRACE MVCCNodeHelper:wrapNodeForReading:145 - Node /user/1:86 is already in context.
20:22:31,473 [http--8080-1$21578710] TRACE CallInterceptor:handleDefault:98 - Executing command: GetNodeCommand{fqn=/user/1:86}.
20:22:31,474 [http--8080-1$21578710] TRACE GetNodeCommand:perform:70 - Found node, returning NodeReference{delegate=UnversionedNode[ /user/1:86 data=[d]]}
20:22:31,481 [http--8080-1$21578710] TRACE MVCCLockingInterceptor:doAfterCall:355 - Nothing to do since there is a transaction in scope.
20:22:31,482 [http--8080-1$21578710] TRACE InvocationContextInterceptor:handleAll:208 - Resetting invocation-scope options
20:22:31,483 [http--8080-1$21578710] TRACE ComponentRegistry:invocationsAllowed:877 - Testing if invocations are allowed.
20:22:31,484 [http--8080-1$21578710] TRACE InvocationContextInterceptor:handleAll:141 - Invoked with command PutKeyValueCommand{fqn=/user/1:86, dataVersion=null, globalTransaction=GlobalTransaction::2, key=d, value=TMUserImpl{_id=1:86, _username='asdf', _SLUsername='iwre', _password='salt', _email='asdf at xomc.om233', _userStateCd=A}} and InvocationContext [InvocationContext{transaction=Transaction[01:916b5f76], globalTransaction=GlobalTransaction::2, transactionContext=TransactionEntry
modificationList: null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false}, originLocal=true}]
20:22:31,498 [http--8080-1$21578710] TRACE InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional context.
20:22:31,499 [http--8080-1$21578710] TRACE InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as Transaction[01:916b5f76] and gtx as GlobalTransaction::2
20:22:31,500 [http--8080-1$21578710] TRACE TxInterceptor:attachGlobalTransaction:446 - local transaction exists - registering global tx if not present for Thread[http--8080-1$21578710,5,main]
20:22:31,501 [http--8080-1$21578710] TRACE TxInterceptor:attachGlobalTransaction:451 - Associated gtx in txTable is GlobalTransaction::2
20:22:31,516 [http--8080-1$21578710] TRACE TxInterceptor:registerTransaction:732 - Transaction Transaction[01:916b5f76] is already registered.
20:22:31,517 [http--8080-1$21578710] TRACE MVCCNodeHelper:wrapNodeForReading:145 - Node /user/1:86 is already in context.
20:22:31,517 [http--8080-1$21578710] TRACE CacheLoaderInterceptor:mustLoad:443 - Don't load [/user/1:86], already have necessary key in memory
20:22:31,518 [http--8080-1$21578710] TRACE CacheLoaderInterceptor:loadIfNeeded:293 - load element /user/1:86
mustLoad=false
20:22:31,534 [http--8080-1$21578710] TRACE MVCCLockManager:lockAndRecord:126 - Attempting to lock /user/1:86
20:22:31,536 [http--8080-1$21578710] TRACE MVCCNodeHelper:wrapNodeForWriting:208 - Retrieving wrapped node /user/1:86
20:22:31,537 [http--8080-1$21578710] TRACE PutKeyValueCommand:perform:76 - Perform('GlobalTransaction::2', '/user/1:86', k='d', v='TMUserImpl{_id=1:86, _username='asdf', _SLUsername='iwre', _password='salt', _email='asdf at xomc.om233', _userStateCd=A}')
20:22:31,551 [http--8080-1$21578710] INFO TMCacheListener:onNodeEvent:41 - : EventImpl{type=NODE_MODIFIED,pre=true, cache=org.jboss.cache.DataContainerImpl [2 nodes, 0 locks], modificationType=PUT_DATA, data={d=TMUserImpl{_id=1:86, _username='asdf', _SLUsername='iwre', _password='salt', _email='asdf at xomc.om233', _userStateCd=A}}, fqn=/user/1:86, transaction=Transaction[01:916b5f76], originLocal=true, targetFqn=null, successful=false, newView=null, buddyGroup=null}
20:22:31,561 [http--8080-1$21578710] TRACE PutKeyValueCommand:perform:88 - Old value is TMUserImpl{_id=1:86, _username='asdf', _SLUsername='iwre', _password='salt', _email='asdf at xomc.om233', _userStateCd=A}, dataLoaded=false
20:22:31,562 [http--8080-1$21578710] INFO TMCacheListener:onNodeEvent:41 - : EventImpl{type=NODE_MODIFIED,pre=false, cache=org.jboss.cache.DataContainerImpl [2 nodes, 0 locks], modificationType=PUT_DATA, data={d=TMUserImpl{_id=1:86, _username='asdf', _SLUsername='iwre', _password='salt', _email='asdf at xomc.om233', _userStateCd=A}}, fqn=/user/1:86, transaction=Transaction[01:916b5f76], originLocal=true, targetFqn=null, successful=false, newView=null, buddyGroup=null}
20:22:31,569 [http--8080-1$21578710] TRACE MVCCLockingInterceptor:doAfterCall:355 - Nothing to do since there is a transaction in scope.
20:22:31,570 [http--8080-1$21578710] TRACE InvocationContextInterceptor:handleAll:208 - Resetting invocation-scope options
20:22:31,613 [http--8080-1$21578710] INFO XmlBeanDefinitionReader:loadBeanDefinitions:323 - Loading XML bean definitions from class path resource [org/springframework/jdbc/support/sql-error-codes.xml]
20:22:31,639 [http--8080-1$21578710] INFO SQLErrorCodesFactory::128 - SQLErrorCodes loaded: [DB2, Derby, H2, HSQL, Informix, MS-SQL, MySQL, Oracle, PostgreSQL, Sybase]
20:22:31,646 [http--8080-1$21578710] INFO UserManagerImpl:updateUser:95 - rolling back tx
20:22:31,646 [http--8080-1$21578710] TRACE TxInterceptor:beforeCompletion:865 - Running beforeCompletion on gtx GlobalTransaction::2
20:22:31,707 [http--8080-1$21578710] TRACE TxInterceptor:setTransactionalContext:71 - Setting up transactional context.
20:22:31,707 [http--8080-1$21578710] TRACE TxInterceptor:setTransactionalContext:72 - Setting tx as Transaction[01:916b5f76] and gtx as GlobalTransaction::2
20:22:31,708 [http--8080-1$21578710] TRACE ComponentRegistry:invocationsAllowed:877 - Testing if invocations are allowed.
20:22:31,708 [http--8080-1$21578710] TRACE TxInterceptor:setTransactionalContext:71 - Setting up transactional context.
20:22:31,715 [http--8080-1$21578710] TRACE TxInterceptor:setTransactionalContext:72 - Setting tx as
Transaction[01:916b5f76] and gtx as GlobalTransaction::2
20:22:31,716 [http--8080-1$21578710] TRACE CacheStoreInterceptor:handlePrepareCommand:195 - transactional so don't put stuff in the cloader yet.
20:22:31,717 [http--8080-1$21578710] TRACE CacheStoreInterceptor:prepareCacheLoader:331 - Cache loader modification list: [PutKeyValueCommand{fqn=/user/1:86, dataVersion=null, globalTransaction=GlobalTransaction::2, key=d, value=TMUserImpl{_id=1:86, _username='asdf', _SLUsername='iwre', _password='salt', _email='asdf at xomc.om233', _userStateCd=A}}]
20:22:31,727 [http--8080-1$21578710] TRACE CacheStoreInterceptor:prepareCacheLoader:339 - Converted method calls to cache loader modifications. List size: 1
20:22:31,728 [http--8080-1$21578710] TRACE CallInterceptor:visitPrepareCommand:70 - Suppressing invocation of method handlePrepareCommand.
20:22:31,729 [http--8080-1$21578710] TRACE MVCCLockingInterceptor:doAfterCall:355 - Nothing to do since there is a transaction in scope.
20:22:31,730 [http--8080-1$21578710] TRACE TxInterceptor:setTransactionalContext:71 - Setting up transactional context.
20:22:31,743 [http--8080-1$21578710] TRACE TxInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as null
20:22:31,744 [http--8080-1$21578710] TRACE TxInterceptor:setTransactionalContext:71 - Setting up transactional context.
20:22:31,745 [http--8080-1$21578710] TRACE TxInterceptor:setTransactionalContext:72 - Setting tx as Transaction[] and gtx as GlobalTransaction::2
20:22:31,745 [http--8080-1$21578710] TRACE ComponentRegistry:invocationsAllowed:877 - Testing if invocations are allowed.
20:22:31,753 [http--8080-1$21578710] TRACE TxInterceptor:afterCompletion:917 - calling aftercompletion for GlobalTransaction::2
20:22:31,759 [http--8080-1$21578710] TRACE TxInterceptor:afterCompletion:940 - Running rollback phase
20:22:31,760 [http--8080-1$21578710] TRACE TxInterceptor:runRollbackPhase:596 - running rollback for GlobalTransaction::2
20:22:31,760 [http--8080-1$21578710] TRACE CacheLoaderInterceptor:visitRollbackCommand:218 - Removing temporarily created nodes
20:22:31,761 [http--8080-1$21578710] TRACE CallInterceptor:visitRollbackCommand:91 - Suppressing invocation of method handleRollbackCommand.
20:22:31,766 [http--8080-1$21578710] TRACE MVCCLockingInterceptor:cleanupLocks:387 - Releasing lock on [/user/1:86] for owner GlobalTransaction::2
20:22:31,767 [http--8080-1$21578710] TRACE MVCCLockManager:unlock:140 - Attempting to unlock /user/1:86
20:22:31,767 [http--8080-1$21578710] TRACE MVCCLockingInterceptor:doAfterCall:355 - Nothing to do since there is a transaction in scope.
20:22:31,768 [http--8080-1$21578710] INFO TMCacheListener:onNodeTransactioncompleted:24 - : EventImpl{type=TRANSACTION_COMPLETED,pre=false, cache=org.jboss.cache.DataContainerImpl [2 nodes, 0 locks], modificationType=null, data=null, fqn=null, transaction=Transaction[], originLocal=true, targetFqn=null, successful=false, newView=null, buddyGroup=null}
20:22:31,779 [http--8080-1$21578710] TRACE TxInterceptor:handleCommitRollback:527 - Finished local commit/rollback method for GlobalTransaction::2
20:22:31,780 [http--8080-1$21578710] TRACE TxInterceptor:afterCompletion:942 - Finished rollback phase
20:22:31,781 [http--8080-1$21578710] TRACE TxInterceptor:setTransactionalContext:71 - Setting up transactional context.
20:22:31,781 [http--8080-1$21578710] TRACE TxInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as null
20:22:31,782 [http--8080-1$21578710] INFO UserManagerImpl:updateUser:103 - User TX: UserTransactionProxy[], status: 6
20:22:32,795 [http--8080-1$21578710] TRACE ComponentRegistry:invocationsAllowed:877 - Testing if invocations are allowed.
20:22:32,796 [http--8080-1$21578710] TRACE InvocationContextInterceptor:handleAll:141 - Invoked with command
GetNodeCommand{fqn=/user/1:86} and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false}, originLocal=true}]
20:22:32,808 [http--8080-1$21578710] TRACE InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional context.
20:22:32,808 [http--8080-1$21578710] TRACE InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as null
20:22:32,809 [http--8080-1$21578710] TRACE MVCCNodeHelper:wrapNodeForReading:136 - Node /user/1:86 is not in context, fetching from container.
20:22:32,811 [http--8080-1$21578710] TRACE CacheLoaderInterceptor:mustLoad:438 - Don't load [/user/1:86], key requested is null
20:22:32,817 [http--8080-1$21578710] TRACE CacheLoaderInterceptor:loadIfNeeded:293 - load element /user/1:86 mustLoad=false
20:22:32,817 [http--8080-1$21578710] TRACE MVCCNodeHelper:wrapNodeForReading:145 - Node /user/1:86 is already in context.
20:22:32,818 [http--8080-1$21578710] TRACE CallInterceptor:handleDefault:98 - Executing command: GetNodeCommand{fqn=/user/1:86}.
20:22:32,819 [http--8080-1$21578710] TRACE GetNodeCommand:perform:70 - Found node, returning NodeReference{delegate=UnversionedNode[ /user/1:86 data=[d]]}
20:22:32,831 [http--8080-1$21578710] TRACE MVCCLockingInterceptor:doAfterCall:350 - Nothing to do since there are no modifications in scope.
20:22:32,832 [http--8080-1$21578710] TRACE InvocationContextInterceptor:handleAll:208 - Resetting invocation-scope options
20:22:32,833 [http--8080-1$21578710] TRACE ComponentRegistry:invocationsAllowed:877 - Testing if invocations are allowed.
20:22:32,833 [http--8080-1$21578710] TRACE InvocationContextInterceptor:handleAll:141 - Invoked with command
GetKeyValueCommand{fqn=/user/1:86, key=d, sendNodeEvent=true} and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false}, originLocal=true}]
20:22:32,844 [http--8080-1$21578710] TRACE InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional context.
20:22:32,845 [http--8080-1$21578710] TRACE InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as null
20:22:32,846 [http--8080-1$21578710] TRACE MVCCNodeHelper:wrapNodeForReading:136 - Node /user/1:86 is not in context, fetching from container.
20:22:32,846 [http--8080-1$21578710] TRACE CacheLoaderInterceptor:mustLoad:443 - Don't load [/user/1:86], already have necessary key in memory
20:22:32,863 [http--8080-1$21578710] TRACE CacheLoaderInterceptor:loadIfNeeded:293 - load element /user/1:86 mustLoad=false
20:22:32,864 [http--8080-1$21578710] TRACE MVCCNodeHelper:wrapNodeForReading:145 - Node /user/1:86 is already in context.
20:22:32,864 [http--8080-1$21578710] TRACE CallInterceptor:handleDefault:98 - Executing command: GetKeyValueCommand{fqn=/user/1:86, key=d, sendNodeEvent=true}.
20:22:32,865 [http--8080-1$21578710] TRACE GetKeyValueCommand:perform:89 - Found value TMUserImpl{_id=1:86, _username='asdf', _SLUsername='iwre', _password='salt', _email='asdf at xomc.om233', _userStateCd=A}
20:22:32,876 [http--8080-1$21578710] TRACE MVCCLockingInterceptor:doAfterCall:350 - Nothing to do since there are no modifications in scope.
20:22:32,879 [http--8080-1$21578710] TRACE InvocationContextInterceptor:handleAll:208 - Resetting invocation-scope options
View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4206415#4206415
Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4206415
More information about the jboss-user
mailing list