thank you, it did fix the exception. Here is the log with the JDBC loader, same problem as
with TCPDelegatinLoader.
| 20:42:38,187 [http--8080-1$23822211] INFO TestUser:getSomething:13 - yoyo:
| 20:42:38,189 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:38,191 [http--8080-1$23822211] 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:42:38,330 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional
context.
| 20:42:38,330 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as
null
| 20:42:38,331 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:136 -
Node /user/1:86 is not in context, fetching from container.
| 20:42:38,332 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:mustLoad:417 - Node
[/user/1:86] is null in memory. Must load? true
| 20:42:38,344 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:loadIfNeeded:293 -
load element /user/1:86 mustLoad=true
| 20:42:38,345 [http--8080-1$23822211] TRACE MVCCLockManager:lockAndRecord:126 -
Attempting to lock /user/1:86
| 20:42:38,369 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@11cd8cc
| 20:42:38,371 [http--8080-1$23822211] TRACE JDBCCacheLoader:prepareAndLogStatement:116
- Executing SQL statement [SELECT '1' FROM jbosscache WHERE fqn = ?] with params
[/user/1:86]
| 20:42:38,372 [http--8080-1$23822211] TRACE NonManagedConnectionFactory:close:176 -
closed non tx connection: com.mysql.jdbc.JDBC4Connection@11cd8cc
| 20:42:38,379 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:136 -
Node /user/1:86 is not in context, fetching from container.
| 20:42:38,464 [http--8080-1$23822211] TRACE CallInterceptor:handleDefault:98 -
Executing command: GetNodeCommand{fqn=/user/1:86}.
| 20:42:38,465 [http--8080-1$23822211] TRACE GetNodeCommand:perform:70 - Found node,
returning null
| 20:42:38,466 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:cleanupLocks:374 -
Releasing lock on [/user/1:86] for owner Thread[http--8080-1$23822211,5,main]
| 20:42:38,466 [http--8080-1$23822211] TRACE MVCCLockManager:unlock:140 - Attempting to
unlock /user/1:86
| 20:42:38,467 [http--8080-1$23822211] TRACE InvocationContextInterceptor:handleAll:208
- Resetting invocation-scope options
| 20:42:38,475 [http--8080-1$23822211] DEBUG NearCacheImpl:getValue:42 - for fqn:
/user/1:86 got this value from cache: null
| 20:42:38,476 [http--8080-1$23822211] INFO UserManagerImpl:getUser:113 - user for id:
1:86 NOT found in cache, will get from DB
| 20:42:38,483 [http--8080-1$23822211] DEBUG
JtaTransactionManager:lookupTransactionManager:587 - Retrieving JTA TransactionManager
from JNDI location [java:/TransactionManager]
| 20:42:38,484 [http--8080-1$23822211] DEBUG
JtaTransactionManager:findUserTransaction:676 - JTA UserTransaction found at default JNDI
location [java:comp/UserTransaction]
| 20:42:38,493 [http--8080-1$23822211] INFO
JtaTransactionManager:checkUserTransactionAndTransactionManager:488 - Using JTA
UserTransaction: UserTransactionProxy[]
| 20:42:38,494 [http--8080-1$23822211] INFO
JtaTransactionManager:checkUserTransactionAndTransactionManager:499 - Using JTA
TransactionManager: TransactionManagerImpl[]
| 20:42:38,496 [http--8080-1$23822211] DEBUG
JtaTransactionManager:findTransactionSynchronizationRegistry:777 - JTA 1.1
[javax.transaction.TransactionSynchronizationRegistry] not available
| 20:42:38,909 [http--8080-1$23822211] INFO TestUser:getSomething:19 - updating user
with good value: TMUserImpl{_id=1:86, _username='asdf',
_SLUsername='1233970958909', _password='{salt}',
_email='asdf(a)xomc.om233', _userStateCd=A}
| 20:42:38,913 [http--8080-1$23822211] INFO UserManagerImpl:updateUser:54 - user TX
before start of TX: UserTransactionProxy[], status: 6
| 20:42:38,920 [http--8080-1$23822211] INFO UserManagerImpl:updateUser:59 - started
user TX: UserTransactionProxy[], status: 0
| 20:42:38,921 [http--8080-1$23822211] DEBUG NearCacheImpl:setValue:53 - setting value
for object:/user/1:86 in cacheId:3
| 20:42:39,118 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:39,119 [http--8080-1$23822211] 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:42:39,128 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional
context.
| 20:42:39,129 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as
Transaction[01:f06abe25] and gtx as null
| 20:42:39,130 [http--8080-1$23822211] TRACE TxInterceptor:attachGlobalTransaction:446 -
local transaction exists - registering global tx if not present for
Thread[http--8080-1$23822211,5,main]
| 20:42:39,131 [http--8080-1$23822211] TRACE TxInterceptor:attachGlobalTransaction:451 -
Associated gtx in txTable is null
| 20:42:39,147 [http--8080-1$23822211] TRACE TransactionTable:getCurrentTransaction:450
- created new GTX: GlobalTransaction:<null>:1, local TX=Transaction[01:f06abe25]
| 20:42:39,148 [http--8080-1$23822211] TRACE TxInterceptor:registerTransaction:719 -
Registering sync handler for tx Transaction[01:f06abe25], gtx
GlobalTransaction:<null>:1
| 20:42:39,152 [http--8080-1$23822211] TRACE TxInterceptor:registerHandler:744 -
registering for TX completion:
SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:1,
tx=com.caucho.transaction.TransactionImpl@13920591))
| 20:42:39,181 [http--8080-1$23822211] INFO
TMCacheListener:onNodeTransactionregistered:29 - :
EventImpl{type=TRANSACTION_REGISTERED,pre=false, cache=org.jboss.cache.DataContainerImpl
[0 nodes, 0 locks], modificationType=null, data=null, fqn=null,
transaction=Transaction[01:f06abe25], originLocal=true, targetFqn=null, successful=false,
newView=null, buddyGroup=null}
| 20:42:39,183 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:136 -
Node /user/1:86 is not in context, fetching from container.
| 20:42:39,189 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:mustLoad:417 - Node
[/user/1:86] is null in memory. Must load? true
| 20:42:39,190 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:loadIfNeeded:293 -
load element /user/1:86 mustLoad=true
| 20:42:39,191 [http--8080-1$23822211] TRACE MVCCLockManager:lockAndRecord:126 -
Attempting to lock /user/1:86
| 20:42:39,215 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@b90ff7
| 20:42:39,222 [http--8080-1$23822211] TRACE JDBCCacheLoader:prepareAndLogStatement:116
- Executing SQL statement [SELECT '1' FROM jbosscache WHERE fqn = ?] with params
[/user/1:86]
| 20:42:39,224 [http--8080-1$23822211] TRACE NonManagedConnectionFactory:close:176 -
closed non tx connection: com.mysql.jdbc.JDBC4Connection@b90ff7
| 20:42:39,224 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:136 -
Node /user/1:86 is not in context, fetching from container.
| 20:42:39,316 [http--8080-1$23822211] TRACE CallInterceptor:handleDefault:98 -
Executing command: GetNodeCommand{fqn=/user/1:86}.
| 20:42:39,317 [http--8080-1$23822211] TRACE GetNodeCommand:perform:70 - Found node,
returning null
| 20:42:39,317 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:doAfterCall:355 -
Nothing to do since there is a transaction in scope.
| 20:42:39,318 [http--8080-1$23822211] TRACE InvocationContextInterceptor:handleAll:208
- Resetting invocation-scope options
| 20:42:39,318 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:39,329 [http--8080-1$23822211] TRACE InvocationContextInterceptor:handleAll:141
- Invoked with command PutKeyValueCommand{fqn=/user/1:86, dataVersion=null,
globalTransaction=GlobalTransaction:<null>:1, key=d, value=TMUserImpl{_id=1:86,
_username='asdf', _SLUsername='1233970958909', _password='{salt}',
_email='asdf(a)xomc.om233', _userStateCd=A}} and InvocationContext
[InvocationContext{transaction=Transaction[01:f06abe25],
globalTransaction=GlobalTransaction:<null>:1, 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:42:39,342 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional
context.
| 20:42:39,343 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as
Transaction[01:f06abe25] and gtx as GlobalTransaction:<null>:1
| 20:42:39,344 [http--8080-1$23822211] TRACE TxInterceptor:attachGlobalTransaction:446 -
local transaction exists - registering global tx if not present for
Thread[http--8080-1$23822211,5,main]
| 20:42:39,344 [http--8080-1$23822211] TRACE TxInterceptor:attachGlobalTransaction:451 -
Associated gtx in txTable is GlobalTransaction:<null>:1
| 20:42:39,357 [http--8080-1$23822211] TRACE TxInterceptor:registerTransaction:732 -
Transaction Transaction[01:f06abe25] is already registered.
| 20:42:39,358 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:136 -
Node /user/1:86 is not in context, fetching from container.
| 20:42:39,359 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:mustLoad:417 - Node
[/user/1:86] is null in memory. Must load? true
| 20:42:39,359 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:loadIfNeeded:293 -
load element /user/1:86 mustLoad=true
| 20:42:39,372 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:loadData:494 -
Attempting to load data for /user/1:86
| 20:42:39,394 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@5db8ff
| 20:42:39,395 [http--8080-1$23822211] TRACE JDBCCacheLoader:prepareAndLogStatement:116
- Executing SQL statement [SELECT node FROM jbosscache WHERE fqn = ?] with params
[/user/1:86]
| 20:42:39,397 [http--8080-1$23822211] TRACE NonManagedConnectionFactory:close:176 -
closed non tx connection: com.mysql.jdbc.JDBC4Connection@5db8ff
| 20:42:39,397 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:loadData:497 - Node
/user/1:86 exists? false
| 20:42:39,494 [http--8080-1$23822211] TRACE MVCCLockManager:lockAndRecord:126 -
Attempting to lock /user
| 20:42:39,495 [http--8080-1$23822211] INFO TMCacheListener:onNodeEvent:41 - :
EventImpl{type=NODE_CREATED,pre=true, cache=org.jboss.cache.DataContainerImpl [0 nodes, 0
locks], modificationType=null, data=null, fqn=/user, transaction=Transaction[01:f06abe25],
originLocal=true, targetFqn=null, successful=false, newView=null, buddyGroup=null}
| 20:42:39,497 [http--8080-1$23822211] TRACE MVCCNodeFactory:createChildNode:140 -
Created new child with fqn [/user]
| 20:42:39,501 [http--8080-1$23822211] INFO TMCacheListener:onNodeEvent:41 - :
EventImpl{type=NODE_CREATED,pre=false, cache=org.jboss.cache.DataContainerImpl [0 nodes, 0
locks], modificationType=null, data=null, fqn=/user, transaction=Transaction[01:f06abe25],
originLocal=true, targetFqn=null, successful=false, newView=null, buddyGroup=null}
| 20:42:39,504 [http--8080-1$23822211] INFO TMCacheListener:onNodeEvent:41 - :
EventImpl{type=NODE_CREATED,pre=true, cache=org.jboss.cache.DataContainerImpl [0 nodes, 0
locks], modificationType=null, data=null, fqn=/user/1:86,
transaction=Transaction[01:f06abe25], originLocal=true, targetFqn=null, successful=false,
newView=null, buddyGroup=null}
| 20:42:39,511 [http--8080-1$23822211] TRACE MVCCNodeFactory:createChildNode:140 -
Created new child with fqn [/user/1:86]
| 20:42:39,512 [http--8080-1$23822211] INFO TMCacheListener:onNodeEvent:41 - :
EventImpl{type=NODE_CREATED,pre=false, cache=org.jboss.cache.DataContainerImpl [0 nodes, 0
locks], modificationType=null, data=null, fqn=/user/1:86,
transaction=Transaction[01:f06abe25], originLocal=true, targetFqn=null, successful=false,
newView=null, buddyGroup=null}
| 20:42:39,513 [http--8080-1$23822211] TRACE PutKeyValueCommand:perform:76 -
Perform('GlobalTransaction:<null>:1', '/user/1:86', k='d',
v='TMUserImpl{_id=1:86, _username='asdf', _SLUsername='1233970958909',
_password='{salt}', _email='asdf(a)xomc.om233', _userStateCd=A}')
| 20:42:39,524 [http--8080-1$23822211] INFO TMCacheListener:onNodeEvent:41 - :
EventImpl{type=NODE_MODIFIED,pre=true, cache=org.jboss.cache.DataContainerImpl [0 nodes, 0
locks], modificationType=PUT_DATA, data={}, fqn=/user/1:86,
transaction=Transaction[01:f06abe25], originLocal=true, targetFqn=null, successful=false,
newView=null, buddyGroup=null}
| 20:42:39,525 [http--8080-1$23822211] TRACE PutKeyValueCommand:perform:88 - Old value
is null, dataLoaded=false
| 20:42:39,532 [http--8080-1$23822211] INFO TMCacheListener:onNodeEvent:41 - :
EventImpl{type=NODE_MODIFIED,pre=false, cache=org.jboss.cache.DataContainerImpl [0 nodes,
0 locks], modificationType=PUT_DATA, data={d=TMUserImpl{_id=1:86,
_username='asdf', _SLUsername='1233970958909', _password='{salt}',
_email='asdf(a)xomc.om233', _userStateCd=A}}, fqn=/user/1:86,
transaction=Transaction[01:f06abe25], originLocal=true, targetFqn=null, successful=false,
newView=null, buddyGroup=null}
| 20:42:39,540 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:doAfterCall:355 -
Nothing to do since there is a transaction in scope.
| 20:42:39,541 [http--8080-1$23822211] TRACE InvocationContextInterceptor:handleAll:208
- Resetting invocation-scope options
| 20:42:39,557 [http--8080-1$23822211] INFO UserManagerImpl:updateUser:87 - committing
tx
| 20:42:39,558 [http--8080-1$23822211] TRACE TxInterceptor:beforeCompletion:865 -
Running beforeCompletion on gtx GlobalTransaction:<null>:1
| 20:42:39,559 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:71 -
Setting up transactional context.
| 20:42:39,559 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:72 -
Setting tx as Transaction[01:f06abe25] and gtx as GlobalTransaction:<null>:1
| 20:42:39,563 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:39,563 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:71 -
Setting up transactional context.
| 20:42:39,564 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:72 -
Setting tx as Transaction[01:f06abe25] and gtx as GlobalTransaction:<null>:1
| 20:42:39,565 [http--8080-1$23822211] TRACE
CacheStoreInterceptor:handlePrepareCommand:195 - transactional so don't put stuff in
the cloader yet.
| 20:42:39,577 [http--8080-1$23822211] TRACE
CacheStoreInterceptor:prepareCacheLoader:331 - Cache loader modification list:
[PutKeyValueCommand{fqn=/user/1:86, dataVersion=null,
globalTransaction=GlobalTransaction:<null>:1, key=d, value=TMUserImpl{_id=1:86,
_username='asdf', _SLUsername='1233970958909', _password='{salt}',
_email='asdf(a)xomc.om233', _userStateCd=A}}]
| 20:42:39,581 [http--8080-1$23822211] TRACE
CacheStoreInterceptor:prepareCacheLoader:339 - Converted method calls to cache loader
modifications. List size: 1
| 20:42:39,610 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@175650e
| 20:42:39,611 [http--8080-1$23822211] TRACE NonManagedConnectionFactory:prepare:83 -
opened tx connection: tx=GlobalTransaction:<null>:1,
con=com.mysql.jdbc.JDBC4Connection@175650e
| 20:42:39,613 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@175650e
| 20:42:39,614 [http--8080-1$23822211] TRACE JDBCCacheLoader:prepareAndLogStatement:116
- Executing SQL statement [SELECT node FROM jbosscache WHERE fqn = ?] with params
[/user/1:86]
| 20:42:39,705 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@175650e
| 20:42:39,706 [http--8080-1$23822211] TRACE JDBCCacheLoader:prepareAndLogStatement:116
- Executing SQL statement [INSERT INTO jbosscache (fqn, node, parent) SELECT ?, ?, ? FROM
jbosscache_D WHERE NOT EXISTS (SELECT fqn FROM jbosscache WHERE fqn = ?)]
| 20:42:39,707 [http--8080-1$23822211] TRACE CacheMarshaller300:objectToObjectStream:173
- Marshalling object {d=TMUserImpl{_id=1:86, _username='asdf',
_SLUsername='1233970958909', _password='{salt}',
_email='asdf(a)xomc.om233', _userStateCd=A}}
| 20:42:39,720 [http--8080-1$23822211] TRACE CacheMarshaller300:marshallObject:446 -
Warning: using object serialization for class com.threadmap.site.user.impl.TMUserImpl
| 20:42:39,726 [http--8080-1$23822211] TRACE CacheMarshaller300:objectToObjectStream:204
- Done serializing object: {d=TMUserImpl{_id=1:86, _username='asdf',
_SLUsername='1233970958909', _password='{salt}',
_email='asdf(a)xomc.om233', _userStateCd=A}}
| 20:42:39,730 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@175650e
| 20:42:39,732 [http--8080-1$23822211] TRACE JDBCCacheLoader:prepareAndLogStatement:116
- Executing SQL statement [SELECT '1' FROM jbosscache WHERE fqn = ?] with params
[/user]
| 20:42:39,734 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@175650e
| 20:42:39,735 [http--8080-1$23822211] TRACE JDBCCacheLoader:prepareAndLogStatement:116
- Executing SQL statement [INSERT INTO jbosscache (fqn, node, parent) SELECT ?, ?, ? FROM
jbosscache_D WHERE NOT EXISTS (SELECT fqn FROM jbosscache WHERE fqn = ?)]
| 20:42:39,748 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@175650e
| 20:42:39,749 [http--8080-1$23822211] TRACE JDBCCacheLoader:prepareAndLogStatement:116
- Executing SQL statement [SELECT '1' FROM jbosscache WHERE fqn = ?] with params
[/]
| 20:42:39,751 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@175650e
| 20:42:39,753 [http--8080-1$23822211] TRACE JDBCCacheLoader:prepareAndLogStatement:116
- Executing SQL statement [INSERT INTO jbosscache (fqn, node, parent) SELECT ?, ?, ? FROM
jbosscache_D WHERE NOT EXISTS (SELECT fqn FROM jbosscache WHERE fqn = ?)]
| 20:42:39,762 [http--8080-1$23822211] TRACE CallInterceptor:visitPrepareCommand:70 -
Suppressing invocation of method handlePrepareCommand.
| 20:42:39,763 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:doAfterCall:355 -
Nothing to do since there is a transaction in scope.
| 20:42:39,768 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:71 -
Setting up transactional context.
| 20:42:39,769 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:72 -
Setting tx as null and gtx as null
| 20:42:39,778 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:71 -
Setting up transactional context.
| 20:42:39,779 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:72 -
Setting tx as Transaction[] and gtx as GlobalTransaction:<null>:1
| 20:42:39,780 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:39,780 [http--8080-1$23822211] TRACE TxInterceptor:afterCompletion:917 - calling
aftercompletion for GlobalTransaction:<null>:1
| 20:42:39,792 [http--8080-1$23822211] TRACE TxInterceptor:afterCompletion:932 - Running
commit phase. One phase? false
| 20:42:39,793 [http--8080-1$23822211] TRACE TxInterceptor:runCommitPhase:549 - Running
commit for GlobalTransaction:<null>:1
| 20:42:39,794 [http--8080-1$23822211] TRACE CallInterceptor:visitCommitCommand:84 -
Suppressing invocation of method handleCommitCommand.
| 20:42:39,795 [http--8080-1$23822211] TRACE ReadCommittedNode:commitUpdate:136 -
Updating node [/user]. deleted=false valid=true changed=true created=true
| 20:42:39,807 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:cleanupLocks:374 -
Releasing lock on [/user] for owner GlobalTransaction:<null>:1
| 20:42:39,808 [http--8080-1$23822211] TRACE MVCCLockManager:unlock:140 - Attempting to
unlock /user
| 20:42:39,808 [http--8080-1$23822211] TRACE ReadCommittedNode:commitUpdate:136 -
Updating node [/user/1:86]. deleted=false valid=true changed=true created=true
| 20:42:39,809 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:cleanupLocks:374 -
Releasing lock on [/user/1:86] for owner GlobalTransaction:<null>:1
| 20:42:39,818 [http--8080-1$23822211] TRACE MVCCLockManager:unlock:140 - Attempting to
unlock /user/1:86
| 20:42:39,820 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:doAfterCall:355 -
Nothing to do since there is a transaction in scope.
| 20:42:39,823 [http--8080-1$23822211] 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=true, newView=null, buddyGroup=null}
| 20:42:39,834 [http--8080-1$23822211] TRACE TxInterceptor:handleCommitRollback:527 -
Finished local commit/rollback method for GlobalTransaction:<null>:1
| 20:42:39,841 [http--8080-1$23822211] TRACE TxInterceptor:afterCompletion:934 -
Finished commit phase
| 20:42:39,842 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:71 -
Setting up transactional context.
| 20:42:39,842 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:72 -
Setting tx as null and gtx as null
| 20:42:39,843 [http--8080-1$23822211] INFO UserManagerImpl:updateUser:99 - User TX:
UserTransactionProxy[], status: 6
| 20:42:39,849 [http--8080-1$23822211] INFO TestUser:getSomething:22 - get user again
| 20:42:39,850 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:39,850 [http--8080-1$23822211] 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:42:39,862 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional
context.
| 20:42:39,863 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as
null
| 20:42:39,863 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:136 -
Node /user/1:86 is not in context, fetching from container.
| 20:42:39,864 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:mustLoad:438 -
Don't load [/user/1:86], key requested is null
| 20:42:39,876 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:loadIfNeeded:293 -
load element /user/1:86 mustLoad=false
| 20:42:39,876 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:145 -
Node /user/1:86 is already in context.
| 20:42:39,877 [http--8080-1$23822211] TRACE CallInterceptor:handleDefault:98 -
Executing command: GetNodeCommand{fqn=/user/1:86}.
| 20:42:39,879 [http--8080-1$23822211] TRACE GetNodeCommand:perform:70 - Found node,
returning NodeReference{delegate=UnversionedNode[ /user/1:86 data=[d]]}
| 20:42:39,890 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:doAfterCall:350 -
Nothing to do since there are no modifications in scope.
| 20:42:39,891 [http--8080-1$23822211] TRACE InvocationContextInterceptor:handleAll:208
- Resetting invocation-scope options
| 20:42:39,892 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:39,898 [http--8080-1$23822211] 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:42:39,906 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional
context.
| 20:42:39,907 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as
null
| 20:42:39,908 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:136 -
Node /user/1:86 is not in context, fetching from container.
| 20:42:39,911 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:mustLoad:443 -
Don't load [/user/1:86], already have necessary key in memory
| 20:42:39,924 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:loadIfNeeded:293 -
load element /user/1:86 mustLoad=false
| 20:42:39,925 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:145 -
Node /user/1:86 is already in context.
| 20:42:39,926 [http--8080-1$23822211] TRACE CallInterceptor:handleDefault:98 -
Executing command: GetKeyValueCommand{fqn=/user/1:86, key=d, sendNodeEvent=true}.
| 20:42:39,926 [http--8080-1$23822211] TRACE GetKeyValueCommand:perform:89 - Found value
TMUserImpl{_id=1:86, _username='asdf', _SLUsername='1233970958909',
_password='{salt}', _email='asdf(a)xomc.om233', _userStateCd=A}
| 20:42:39,935 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:doAfterCall:350 -
Nothing to do since there are no modifications in scope.
| 20:42:39,936 [http--8080-1$23822211] TRACE InvocationContextInterceptor:handleAll:208
- Resetting invocation-scope options
| 20:42:39,936 [http--8080-1$23822211] DEBUG NearCacheImpl:getValue:42 - for fqn:
/user/1:86 got this value from cache: TMUserImpl{_id=1:86, _username='asdf',
_SLUsername='1233970958909', _password='{salt}',
_email='asdf(a)xomc.om233', _userStateCd=A}
| 20:42:39,949 [http--8080-1$23822211] INFO UserManagerImpl:getUser:111 - user for id:
1:86 was found in cache: TMUserImpl{_id=1:86, _username='asdf',
_SLUsername='1233970958909', _password='{salt}',
_email='asdf(a)xomc.om233', _userStateCd=A}
| 20:42:39,950 [http--8080-1$23822211] INFO TestUser:getSomething:24 - user before bad
value: TMUserImpl{_id=1:86, _username='asdf', _SLUsername='1233970958909',
_password='{salt}', _email='asdf(a)xomc.om233', _userStateCd=A}
| 20:42:39,951 [http--8080-1$23822211] INFO TestUser:getSomething:31 - before update :
TMUserImpl{_id=1:86, _username='asdf', _SLUsername='asdf',
_password='{salt}', _email='asdf(a)xomc.om233', _userStateCd=A}
| 20:42:39,962 [http--8080-1$23822211] INFO UserManagerImpl:updateUser:54 - user TX
before start of TX: UserTransactionProxy[], status: 6
| 20:42:39,963 [http--8080-1$23822211] INFO UserManagerImpl:updateUser:59 - started
user TX: UserTransactionProxy[], status: 0
| 20:42:39,963 [http--8080-1$23822211] DEBUG NearCacheImpl:setValue:53 - setting value
for object:/user/1:86 in cacheId:3
| 20:42:39,964 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:39,968 [http--8080-1$23822211] 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:42:39,979 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional
context.
| 20:42:39,980 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as
Transaction[01:a0d7f853] and gtx as null
| 20:42:39,981 [http--8080-1$23822211] TRACE TxInterceptor:attachGlobalTransaction:446 -
local transaction exists - registering global tx if not present for
Thread[http--8080-1$23822211,5,main]
| 20:42:39,981 [http--8080-1$23822211] TRACE TxInterceptor:attachGlobalTransaction:451 -
Associated gtx in txTable is null
| 20:42:39,999 [http--8080-1$23822211] TRACE TransactionTable:getCurrentTransaction:450
- created new GTX: GlobalTransaction:<null>:2, local TX=Transaction[01:a0d7f853]
| 20:42:40,000 [http--8080-1$23822211] TRACE TxInterceptor:registerTransaction:719 -
Registering sync handler for tx Transaction[01:a0d7f853], gtx
GlobalTransaction:<null>:2
| 20:42:40,001 [http--8080-1$23822211] TRACE TxInterceptor:registerHandler:744 -
registering for TX completion:
SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:2,
tx=com.caucho.transaction.TransactionImpl@13920591))
| 20:42:40,013 [http--8080-1$23822211] 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:a0d7f853], originLocal=true, targetFqn=null, successful=false,
newView=null, buddyGroup=null}
| 20:42:40,014 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:136 -
Node /user/1:86 is not in context, fetching from container.
| 20:42:40,027 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:mustLoad:438 -
Don't load [/user/1:86], key requested is null
| 20:42:40,028 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:loadIfNeeded:293 -
load element /user/1:86 mustLoad=false
| 20:42:40,029 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:145 -
Node /user/1:86 is already in context.
| 20:42:40,030 [http--8080-1$23822211] TRACE CallInterceptor:handleDefault:98 -
Executing command: GetNodeCommand{fqn=/user/1:86}.
| 20:42:40,031 [http--8080-1$23822211] TRACE GetNodeCommand:perform:70 - Found node,
returning NodeReference{delegate=UnversionedNode[ /user/1:86 data=[d]]}
| 20:42:40,040 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:doAfterCall:355 -
Nothing to do since there is a transaction in scope.
| 20:42:40,041 [http--8080-1$23822211] TRACE InvocationContextInterceptor:handleAll:208
- Resetting invocation-scope options
| 20:42:40,045 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:40,046 [http--8080-1$23822211] TRACE InvocationContextInterceptor:handleAll:141
- Invoked with command PutKeyValueCommand{fqn=/user/1:86, dataVersion=null,
globalTransaction=GlobalTransaction:<null>:2, key=d, value=TMUserImpl{_id=1:86,
_username='asdf', _SLUsername='asdf', _password='{salt}',
_email='asdf(a)xomc.om233', _userStateCd=A}} and InvocationContext
[InvocationContext{transaction=Transaction[01:a0d7f853],
globalTransaction=GlobalTransaction:<null>: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:42:40,056 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional
context.
| 20:42:40,057 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as
Transaction[01:a0d7f853] and gtx as GlobalTransaction:<null>:2
| 20:42:40,058 [http--8080-1$23822211] TRACE TxInterceptor:attachGlobalTransaction:446 -
local transaction exists - registering global tx if not present for
Thread[http--8080-1$23822211,5,main]
| 20:42:40,058 [http--8080-1$23822211] TRACE TxInterceptor:attachGlobalTransaction:451 -
Associated gtx in txTable is GlobalTransaction:<null>:2
| 20:42:40,073 [http--8080-1$23822211] TRACE TxInterceptor:registerTransaction:732 -
Transaction Transaction[01:a0d7f853] is already registered.
| 20:42:40,075 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:145 -
Node /user/1:86 is already in context.
| 20:42:40,076 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:mustLoad:443 -
Don't load [/user/1:86], already have necessary key in memory
| 20:42:40,077 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:loadIfNeeded:293 -
load element /user/1:86 mustLoad=false
| 20:42:40,093 [http--8080-1$23822211] TRACE MVCCLockManager:lockAndRecord:126 -
Attempting to lock /user/1:86
| 20:42:40,094 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForWriting:208 -
Retrieving wrapped node /user/1:86
| 20:42:40,095 [http--8080-1$23822211] TRACE PutKeyValueCommand:perform:76 -
Perform('GlobalTransaction:<null>:2', '/user/1:86', k='d',
v='TMUserImpl{_id=1:86, _username='asdf', _SLUsername='asdf',
_password='{salt}', _email='asdf(a)xomc.om233', _userStateCd=A}')
| 20:42:40,106 [http--8080-1$23822211] 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='asdf', _password='{salt}', _email='asdf(a)xomc.om233',
_userStateCd=A}}, fqn=/user/1:86, transaction=Transaction[01:a0d7f853], originLocal=true,
targetFqn=null, successful=false, newView=null, buddyGroup=null}
| 20:42:40,116 [http--8080-1$23822211] TRACE PutKeyValueCommand:perform:88 - Old value
is TMUserImpl{_id=1:86, _username='asdf', _SLUsername='asdf',
_password='{salt}', _email='asdf(a)xomc.om233', _userStateCd=A},
dataLoaded=false
| 20:42:40,117 [http--8080-1$23822211] 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='asdf', _password='{salt}',
_email='asdf(a)xomc.om233', _userStateCd=A}}, fqn=/user/1:86,
transaction=Transaction[01:a0d7f853], originLocal=true, targetFqn=null, successful=false,
newView=null, buddyGroup=null}
| 20:42:40,127 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:doAfterCall:355 -
Nothing to do since there is a transaction in scope.
| 20:42:40,132 [http--8080-1$23822211] TRACE InvocationContextInterceptor:handleAll:208
- Resetting invocation-scope options
| 20:42:40,165 [http--8080-1$23822211] INFO
XmlBeanDefinitionReader:loadBeanDefinitions:323 - Loading XML bean definitions from class
path resource [org/springframework/jdbc/support/sql-error-codes.xml]
| 20:42:40,186 [http--8080-1$23822211] INFO SQLErrorCodesFactory:<init>:128 -
SQLErrorCodes loaded: [DB2, Derby, H2, HSQL, Informix, MS-SQL, MySQL, Oracle, PostgreSQL,
Sybase]
| 20:42:40,192 [http--8080-1$23822211] INFO UserManagerImpl:updateUser:91 - rolling
back tx
| 20:42:40,192 [http--8080-1$23822211] TRACE TxInterceptor:beforeCompletion:865 -
Running beforeCompletion on gtx GlobalTransaction:<null>:2
| 20:42:40,252 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:71 -
Setting up transactional context.
| 20:42:40,253 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:72 -
Setting tx as Transaction[01:a0d7f853] and gtx as GlobalTransaction:<null>:2
| 20:42:40,253 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:40,254 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:71 -
Setting up transactional context.
| 20:42:40,261 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:72 -
Setting tx as Transaction[01:a0d7f853] and gtx as GlobalTransaction:<null>:2
| 20:42:40,262 [http--8080-1$23822211] TRACE
CacheStoreInterceptor:handlePrepareCommand:195 - transactional so don't put stuff in
the cloader yet.
| 20:42:40,262 [http--8080-1$23822211] TRACE
CacheStoreInterceptor:prepareCacheLoader:331 - Cache loader modification list:
[PutKeyValueCommand{fqn=/user/1:86, dataVersion=null,
globalTransaction=GlobalTransaction:<null>:2, key=d, value=TMUserImpl{_id=1:86,
_username='asdf', _SLUsername='asdf', _password='{salt}',
_email='asdf(a)xomc.om233', _userStateCd=A}}]
| 20:42:40,275 [http--8080-1$23822211] TRACE
CacheStoreInterceptor:prepareCacheLoader:339 - Converted method calls to cache loader
modifications. List size: 1
| 20:42:40,276 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@175650e
| 20:42:40,277 [http--8080-1$23822211] TRACE NonManagedConnectionFactory:prepare:83 -
opened tx connection: tx=GlobalTransaction:<null>:2,
con=com.mysql.jdbc.JDBC4Connection@175650e
| 20:42:40,277 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@175650e
| 20:42:40,290 [http--8080-1$23822211] TRACE JDBCCacheLoader:prepareAndLogStatement:116
- Executing SQL statement [SELECT node FROM jbosscache WHERE fqn = ?] with params
[/user/1:86]
| 20:42:40,297 [http--8080-1$23822211] TRACE
CacheMarshaller300:objectFromObjectStream:166 - Unmarshalled object
{d=TMUserImpl{_id=1:86, _username='asdf', _SLUsername='1233970958909',
_password='{salt}', _email='asdf(a)xomc.om233', _userStateCd=A}}
| 20:42:40,298 [http--8080-1$23822211] TRACE
NonManagedConnectionFactory:getConnection:107 - using connection:
com.mysql.jdbc.JDBC4Connection@175650e
| 20:42:40,304 [http--8080-1$23822211] TRACE JDBCCacheLoader:prepareAndLogStatement:116
- Executing SQL statement [UPDATE jbosscache SET node = ? WHERE fqn = ?]
| 20:42:40,305 [http--8080-1$23822211] TRACE CacheMarshaller300:objectToObjectStream:173
- Marshalling object {d=TMUserImpl{_id=1:86, _username='asdf',
_SLUsername='asdf', _password='{salt}', _email='asdf(a)xomc.om233',
_userStateCd=A}}
| 20:42:40,317 [http--8080-1$23822211] TRACE CacheMarshaller300:marshallObject:446 -
Warning: using object serialization for class com.threadmap.site.user.impl.TMUserImpl
| 20:42:40,318 [http--8080-1$23822211] TRACE CacheMarshaller300:objectToObjectStream:204
- Done serializing object: {d=TMUserImpl{_id=1:86, _username='asdf',
_SLUsername='asdf', _password='{salt}', _email='asdf(a)xomc.om233',
_userStateCd=A}}
| 20:42:40,331 [http--8080-1$23822211] TRACE CallInterceptor:visitPrepareCommand:70 -
Suppressing invocation of method handlePrepareCommand.
| 20:42:40,332 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:doAfterCall:355 -
Nothing to do since there is a transaction in scope.
| 20:42:40,333 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:71 -
Setting up transactional context.
| 20:42:40,333 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:72 -
Setting tx as null and gtx as null
| 20:42:40,344 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:71 -
Setting up transactional context.
| 20:42:40,350 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:72 -
Setting tx as Transaction[] and gtx as GlobalTransaction:<null>:2
| 20:42:40,351 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:40,351 [http--8080-1$23822211] TRACE TxInterceptor:afterCompletion:917 - calling
aftercompletion for GlobalTransaction:<null>:2
| 20:42:40,358 [http--8080-1$23822211] TRACE TxInterceptor:afterCompletion:940 - Running
rollback phase
| 20:42:40,359 [http--8080-1$23822211] TRACE TxInterceptor:runRollbackPhase:596 -
running rollback for GlobalTransaction:<null>:2
| 20:42:40,360 [http--8080-1$23822211] TRACE
CacheLoaderInterceptor:visitRollbackCommand:218 - Removing temporarily created nodes
| 20:42:40,360 [http--8080-1$23822211] TRACE CallInterceptor:visitRollbackCommand:91 -
Suppressing invocation of method handleRollbackCommand.
| 20:42:40,361 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:cleanupLocks:387 -
Releasing lock on [/user/1:86] for owner GlobalTransaction:<null>:2
| 20:42:40,369 [http--8080-1$23822211] TRACE MVCCLockManager:unlock:140 - Attempting to
unlock /user/1:86
| 20:42:40,370 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:doAfterCall:355 -
Nothing to do since there is a transaction in scope.
| 20:42:40,371 [http--8080-1$23822211] 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:42:40,385 [http--8080-1$23822211] TRACE TxInterceptor:handleCommitRollback:527 -
Finished local commit/rollback method for GlobalTransaction:<null>:2
| 20:42:40,386 [http--8080-1$23822211] TRACE TxInterceptor:afterCompletion:942 -
Finished rollback phase
| 20:42:40,387 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:71 -
Setting up transactional context.
| 20:42:40,388 [http--8080-1$23822211] TRACE TxInterceptor:setTransactionalContext:72 -
Setting tx as null and gtx as null
| 20:42:40,389 [http--8080-1$23822211] INFO UserManagerImpl:updateUser:99 - User TX:
UserTransactionProxy[], status: 6
| 20:42:41,400 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:41,400 [http--8080-1$23822211] 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:42:41,415 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional
context.
| 20:42:41,418 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as
null
| 20:42:41,418 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:136 -
Node /user/1:86 is not in context, fetching from container.
| 20:42:41,419 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:mustLoad:438 -
Don't load [/user/1:86], key requested is null
| 20:42:41,427 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:loadIfNeeded:293 -
load element /user/1:86 mustLoad=false
| 20:42:41,429 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:145 -
Node /user/1:86 is already in context.
| 20:42:41,429 [http--8080-1$23822211] TRACE CallInterceptor:handleDefault:98 -
Executing command: GetNodeCommand{fqn=/user/1:86}.
| 20:42:41,430 [http--8080-1$23822211] TRACE GetNodeCommand:perform:70 - Found node,
returning NodeReference{delegate=UnversionedNode[ /user/1:86 data=[d]]}
| 20:42:41,443 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:doAfterCall:350 -
Nothing to do since there are no modifications in scope.
| 20:42:41,444 [http--8080-1$23822211] TRACE InvocationContextInterceptor:handleAll:208
- Resetting invocation-scope options
| 20:42:41,445 [http--8080-1$23822211] TRACE ComponentRegistry:invocationsAllowed:877 -
Testing if invocations are allowed.
| 20:42:41,446 [http--8080-1$23822211] 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:42:41,457 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:71 - Setting up transactional
context.
| 20:42:41,459 [http--8080-1$23822211] TRACE
InvocationContextInterceptor:setTransactionalContext:72 - Setting tx as null and gtx as
null
| 20:42:41,459 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:136 -
Node /user/1:86 is not in context, fetching from container.
| 20:42:41,460 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:mustLoad:443 -
Don't load [/user/1:86], already have necessary key in memory
| 20:42:41,477 [http--8080-1$23822211] TRACE CacheLoaderInterceptor:loadIfNeeded:293 -
load element /user/1:86 mustLoad=false
| 20:42:41,478 [http--8080-1$23822211] TRACE MVCCNodeHelper:wrapNodeForReading:145 -
Node /user/1:86 is already in context.
| 20:42:41,479 [http--8080-1$23822211] TRACE CallInterceptor:handleDefault:98 -
Executing command: GetKeyValueCommand{fqn=/user/1:86, key=d, sendNodeEvent=true}.
| 20:42:41,484 [http--8080-1$23822211] TRACE GetKeyValueCommand:perform:89 - Found value
TMUserImpl{_id=1:86, _username='asdf', _SLUsername='asdf',
_password='{salt}', _email='asdf(a)xomc.om233', _userStateCd=A}
| 20:42:41,498 [http--8080-1$23822211] TRACE MVCCLockingInterceptor:doAfterCall:350 -
Nothing to do since there are no modifications in scope.
| 20:42:41,499 [http--8080-1$23822211] TRACE InvocationContextInterceptor:handleAll:208
- Resetting invocation-scope options
| 20:42:41,499 [http--8080-1$23822211] DEBUG NearCacheImpl:getValue:42 - for fqn:
/user/1:86 got this value from cache: TMUserImpl{_id=1:86, _username='asdf',
_SLUsername='asdf', _password='{salt}', _email='asdf(a)xomc.om233',
_userStateCd=A}
| 20:42:41,513 [http--8080-1$23822211] INFO UserManagerImpl:getUser:111 - user for id:
1:86 was found in cache: TMUserImpl{_id=1:86, _username='asdf',
_SLUsername='asdf', _password='{salt}', _email='asdf(a)xomc.om233',
_userStateCd=A}
| 20:42:41,515 [http--8080-1$23822211] INFO TestUser:getSomething:45 - after update :
TMUserImpl{_id=1:86, _username='asdf', _SLUsername='asdf',
_password='{salt}', _email='asdf(a)xomc.om233', _userStateCd=A}
|
View the original post :
http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4207894#...
Reply to the post :
http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&a...