1 2 Previous Next 19 Replies Latest reply on Mar 12, 2008 9:34 AM by manik

    Config Question

    lovelyliatroim

      Hi Folks,
      I have a cache configured with a JDBCCacheLoader and in my cache i have a region where i dont want any nodes in the cache memory i.e they will be retrieved through the cacheloader. How do i configure the region to have no nodes in memory since if i set it to 0 then this means no limit?? Maybe -1??

      Ok next question. Im running some tests where im writing 32kb image to the DB through JBossCache. This is the region where i would like it to have no nodes in memory but currently have it configured to 1. Now if i write say 5000 objects/blobs to the cache/db i get a good throughput figure around 95 per second, however if i run the same test for a sustained period of time this figure drops down to around 20 per sec. Thats a big drop. Now I have a feeling that 2 things might be causing or attributing to the drop. First being the asynch mode, havent looked to see how it works under the hood but i assume that the write requests are buffered somewhere in memory and the heavier the load the more write requests will be buffered, when i run 5,000 writes, its a short burst but when i run the test over a sustained period all these writes are adding on to the asynch buffer thus increasing the load in memory and slowing down throughput. 2nd thing that i think is causing a problem is the eviction of the 1 node i have in memory. When the test is running i get a flury of debug messages saying "node added" and then it pauses for 1-2 seconds and then i start seeing


      Eviction of /image/3457 timed out, retrying later

      And it generally comes in groups of 3´s and then carries on writing, pauses again, outputs the above and carries on again. Now if i could configure my region to tell the cache to have no nodes in memory then this would probably remove this problem or is there something else i can do??
      Any thoughts on why the big drop over time??

      Another question i was thinking about, is there any way to give the asynch buffer more time i.e to catch up or how exactly does the asynch mode work under the hood.

      And my last question. ;) Its off topic a bit, do you know what JBoss AS 5.0 milestones are i.e when the final production release will be.(I see the road map but no dates http://jira.jboss.com/jira/browse/JBAS?report=com.atlassian.jira.plugin.system.project:roadmap-panel ) In a bit of dilema as to whether to use JBoss Cache 1.4 with JBoss AS 4.2.x or go with JBoss Cache 2.0 and AS 5.0 Beta3 at the moment!! My production release date is May....any thoughts on it, pro´s or cons??

      Any help or comments is much appreciated,
      LL

        • 1. Re: Config Question
          manik

           

          "lovelyliatroim" wrote:

          I have a cache configured with a JDBCCacheLoader and in my cache i have a region where i dont want any nodes in the cache memory i.e they will be retrieved through the cacheloader. How do i configure the region to have no nodes in memory since if i set it to 0 then this means no limit?? Maybe -1??


          Definitely a limitation. Could you please create a feature request in JIRA for this and vote for it?

          "lovelyliatroim" wrote:

          Ok next question. Im running some tests where im writing 32kb image to the DB through JBossCache. This is the region where i would like it to have no nodes in memory but currently have it configured to 1. Now if i write say 5000 objects/blobs to the cache/db i get a good throughput figure around 95 per second, however if i run the same test for a sustained period of time this figure drops down to around 20 per sec. Thats a big drop. Now I have a feeling that 2 things might be causing or attributing to the drop. First being the asynch mode, havent looked to see how it works under the hood but i assume that the write requests are buffered somewhere in memory and the heavier the load the more write requests will be buffered, when i run 5,000 writes, its a short burst but when i run the test over a sustained period all these writes are adding on to the asynch buffer thus increasing the load in memory and slowing down throughput. 2nd thing that i think is causing a problem is the eviction of the 1 node i have in memory. When the test is running i get a flury of debug messages saying "node added" and then it pauses for 1-2 seconds and then i start seeing

          Eviction of /image/3457 timed out, retrying later

          And it generally comes in groups of 3´s and then carries on writing, pauses again, outputs the above and carries on again. Now if i could configure my region to tell the cache to have no nodes in memory then this would probably remove this problem or is there something else i can do??
          Any thoughts on why the big drop over time??


          What could be your problem is how often your eviction thread kicks in. If you have enough memory to deal with temporary spikes before the eviction thread clears down unused nodes, I'd set this not to run too frequently.

          "lovelyliatroim" wrote:

          Another question i was thinking about, is there any way to give the asynch buffer more time i.e to catch up or how exactly does the asynch mode work under the hood.


          I don't think it is replication, although you could tune it by using a ReplicationQueue (by default, even async replication happens immediately; the caller thread just doesn't wait for the response). See the user guide/sample configs for how to use the ReplicationQueue to defer this; it can be triggered either by time or size.

          "lovelyliatroim" wrote:

          And my last question. ;) Its off topic a bit, do you know what JBoss AS 5.0 milestones are i.e when the final production release will be.(I see the road map but no dates http://jira.jboss.com/jira/browse/JBAS?report=com.atlassian.jira.plugin.system.project:roadmap-panel ) In a bit of dilema as to whether to use JBoss Cache 1.4 with JBoss AS 4.2.x or go with JBoss Cache 2.0 and AS 5.0 Beta3 at the moment!! My production release date is May....any thoughts on it, pro´s or cons??


          Sorry - that is a question for the JBoss AS guys. :-) JBoss AS will most likely ship with JBoss Cache 2.1.0, BTW.

          Also, if you are using the cache directly (i.e., packaged in your webapp or ear), you could even use 2.0.0/2.1.0 with JBoss AS 4.x. See http://wiki.jboss.org/wiki/Wiki.jsp?page=JBossCacheAsCompatibility

          • 2. Re: Config Question
            lovelyliatroim

             



            Definitely a limitation. Could you please create a feature request in JIRA for this and vote for it?

            If i find out how or where to do this i will ;).


            What could be your problem is how often your eviction thread kicks in. If you have enough memory to deal with temporary spikes before the eviction thread clears down unused nodes, I'd set this not to run too frequently.

            Currently running every 5 seconds, will set it for a longer time period. Can you set the "wakeUpIntervalSeconds" on a region basis or is it a global cache setting??



            I don't think it is replication, although you could tune it by using a ReplicationQueue (by default, even async replication happens immediately; the caller thread just doesn't wait for the response). See the user guide/sample configs for how to use the ReplicationQueue to defer this; it can be triggered either by time or size.

            Hmmm im not sure we are talking about the same async, I´m talking about the asynch mode with the cacheloader i.e JDBCCacheLoader nothing to do with replication. Ive actually set this cache as LOCAL so i have no replication going on what so ever. What I was asking was is there any way to get the asynch buffer for the JDBCCaheLoader to run more often/quicker to clear the buffer as quick as possible?? Reason i ask is that when i run say 5,000 writes and stop, i check the the DB to see how many records are written and i can see that over the space of one to three,four minutes it eventually will write all records in the DB. But it is this 3-4 minutes time lag that worries me, in production it wont get this 3-4 min break. Maybe it actually is running as fast as possible to clear the buffer but due to the fact it is writing images it actually takes this long!!



            Also, if you are using the cache directly (i.e., packaged in your webapp or ear), you could even use 2.0.0/2.1.0 with JBoss AS 4.x. See http://wiki.jboss.org/wiki/Wiki.jsp?page=JBossCacheAsCompatibility

            Thanks for the info, I already tried 4.2.X with JBossCache 2.0 and tried deploying as an MBean, this is a while back now, but i remember i did run into problems trying to deploy it as an MBean and when i did get it to work none of the statistics were getting updated in jmx-console. So was kind of put off the combination of 4.2.x with JbossCache 2.0 but i might have to venture back with this combination!

            Thanks Manik,
            LL


            • 3. Re: Config Question
              lovelyliatroim

               


              Definitely a limitation. Could you please create a feature request in JIRA for this and vote for it?

              Done.
              http://jira.jboss.org/jira/browse/JBCACHE-1274


              • 4. Re: Config Question
                manik

                 

                "lovelyliatroim" wrote:

                Currently running every 5 seconds, will set it for a longer time period. Can you set the "wakeUpIntervalSeconds" on a region basis or is it a global cache setting??


                No, this is a cache-wide setting.

                "lovelyliatroim" wrote:

                Hmmm im not sure we are talking about the same async, I'm talking about the asynch mode with the cacheloader i.e JDBCCacheLoader nothing to do with replication. Ive actually set this cache as LOCAL so i have no replication going on what so ever. What I was asking was is there any way to get the asynch buffer for the JDBCCaheLoader to run more often/quicker to clear the buffer as quick as possible?? Reason i ask is that when i run say 5,000 writes and stop, i check the the DB to see how many records are written and i can see that over the space of one to three,four minutes it eventually will write all records in the DB. But it is this 3-4 minutes time lag that worries me, in production it wont get this 3-4 min break. Maybe it actually is running as fast as possible to clear the buffer but due to the fact it is writing images it actually takes this long!!


                Oh right - sorry, forget what I said about replication queues then! :-)

                See the JavaDocs for the AsyncCacheLoader wrapper, which has all the options you can add to your cache loader. You can control your batch size and triggers.

                "lovelyliatroim" wrote:

                Thanks for the info, I already tried 4.2.X with JBossCache 2.0 and tried deploying as an MBean, this is a while back now, but i remember i did run into problems trying to deploy it as an MBean and when i did get it to work none of the statistics were getting updated in jmx-console. So was kind of put off the combination of 4.2.x with JbossCache 2.0 but i might have to venture back with this combination!


                You may not be able to use 2.X as an MBean in AS 4.2.X since AS 4.2.X ships with JBC 1.4.X. You may have to package JBC 2.X in your app and start it programmatically.

                Otherwise, you could create a SAR with JBC 2.X libraries and have it deployed and registered as an MBean there. Note that I haven't tried this approach yet though. If you do, and it works, do you mind sharing what you learned on http://wiki.jboss.org/wiki/Wiki.jsp?page=JBossCacheAsCompatibility ?

                • 5. Re: Config Question
                  lovelyliatroim

                   


                  No, this is a cache-wide setting.

                  Thats what i thought!


                  See the JavaDocs for the AsyncCacheLoader wrapper, which has all the options you can add to your cache loader. You can control your batch size and triggers.

                  Super, will have a look and play around with it.


                  Otherwise, you could create a SAR with JBC 2.X libraries and have it deployed and registered as an MBean there. Note that I haven't tried this approach yet though. If you do, and it works, do you mind sharing what you learned on http://wiki.jboss.org/wiki/Wiki.jsp?page=JBossCacheAsCompatibility ?

                  If i do I will post my findings.


                  • 6. Re: Config Question
                    lovelyliatroim

                    Right, in the quest for higher throughput using my cache and the JDBCCacheLoader im experiencing what to me is strange behaviour.

                    Here is my config for the record

                    <?xml version="1.0" encoding="UTF-8"?>
                    
                    <!-- ===================================================================== -->
                    <!-- -->
                    <!-- Sample TreeCache Service Configuration -->
                    <!-- -->
                    <!-- ===================================================================== -->
                    
                    <server>
                    
                     <!-- ==================================================================== -->
                     <!-- Defines TreeCache configuration -->
                     <!-- ==================================================================== -->
                    
                     <mbean code="org.jboss.cache.jmx.CacheJmxWrapper"
                     name="jboss.cache:service=CMDSPersistentCache">
                    
                     <depends>jboss:service=Naming</depends>
                     <depends>jboss:service=TransactionManager</depends>
                    <depends>
                    jboss.jca:service=DataSourceBinding,name=cmdsDB
                    </depends>
                    
                     <!--
                     Configure the TransactionManager
                     -->
                     <attribute name="TransactionManagerLookupClass">org.jboss.cache.transaction.GenericTransactionManagerLookup
                     </attribute>
                    
                    
                    
                    
                     <!--
                     Node locking level : SERIALIZABLE
                     REPEATABLE_READ (default)
                     READ_COMMITTED
                     READ_UNCOMMITTED
                     NONE
                     -->
                     <attribute name="IsolationLevel">REPEATABLE_READ</attribute>
                    
                     <!--
                     Valid modes are LOCAL
                     REPL_ASYNC
                     REPL_SYNC
                     INVALIDATION_ASYNC
                     INVALIDATION_SYNC
                     -->
                     <attribute name="CacheMode">LOCAL</attribute>
                    
                     <!-- Name of cluster. Needs to be the same for all clusters, in order
                     to find each other
                     -->
                     <attribute name="ClusterName">CMDS-Cluster</attribute>
                    
                     <!-- JGroups protocol stack properties NOT NEEDED since CacheMode is LOCAL -->
                    
                     <attribute name="LockAcquisitionTimeout">15000</attribute>
                    
                     <attribute name="StateRetrievalTimeout">6000</attribute>
                     <attribute name="SyncReplTimeout">6000</attribute>
                     <!--<attribute name="NodeLockingScheme">OPTIMISTIC</attribute>
                     -->
                    
                     <!-- Specific eviction policy configurations. This is LRU -->
                     <attribute name="EvictionPolicyConfig">
                     <config>
                     <attribute name="wakeUpIntervalSeconds">30</attribute>
                     <attribute name="eventQueueSize">200000</attribute>
                     <attribute name="policyClass">org.jboss.cache.eviction.LRUPolicy</attribute>
                    
                     <region name="/_default_">
                     <attribute name="maxNodes">5000</attribute>
                     <attribute name="timeToLiveSeconds">1000</attribute>
                     </region>
                     <region name="/quotes">
                     <attribute name="maxNodes">1</attribute>
                     <attribute name="timeToLiveSeconds">10000</attribute>
                     </region>
                     </config>
                     </attribute>
                    
                     <attribute name="CacheLoaderConfig" replace="false">
                     <config>
                     <!-- are the cache loaders shared in a cluster? -->
                     <shared>false</shared>
                     <async>true</async>
                     <fetchPersistentState>false</fetchPersistentState>
                     <ignoreModifications>false</ignoreModifications>
                     <purgeOnStartup>false</purgeOnStartup>
                    
                     <cacheloader>
                     <class>org.jboss.cache.loader.JDBCCacheLoader</class>
                    
                     <properties>
                     cache.jdbc.datasource=java:/cmdsDB
                     </properties>
                    
                     </cacheloader>
                    
                     </config>
                     </attribute>
                    
                     </mbean>
                    
                    
                    </server>
                    
                    


                    The way i was thinking was this, i wanted to see could i get a higher throughput for my cache and thought maybe if i switched the NodeLockingScheme from the default pessimistic to optimistic that i might be more throughput. Now here is where the strange thing happened or maybe it is my mis-understanding along the way. The throughput is higher alright in OPTIMISTIC mode but the reason its higher is because it aint making any writes to the DB any more!! There are no entries in the DB at all!! If i look at the jmx-console i see the record in the caches memory but it aint in the DB. Records are written with PESSIMISTIC mode but not with OPTIMISTIC, any ideas why im seeing this behaviour?.

                    Log entries in OPTIMISTIC mode are as follows


                    2008-01-23 14:21:18,690 INFO [STDOUT] 2008-01-23 14:21:18,690 DEBUG [at.sit.cdms.web.actions.ActionFactory] - Looking for bean addItem
                    
                    2008-01-23 14:21:18,690 DEBUG [at.sit.cdms.web.actions.ActionFactory] Looking for bean addItem
                    
                    2008-01-23 14:21:18,690 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'addItem'
                    
                    2008-01-23 14:21:18,690 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-127.0.0.1-8080-1,5,jboss]
                    
                    2008-01-23 14:21:18,690 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/2)
                    
                    2008-01-23 14:21:18,706 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                    
                    2008-01-23 14:21:18,706 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:2
                    
                    2008-01-23 14:21:18,706 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:2
                    
                    2008-01-23 14:21:18,706 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                    
                    2008-01-23 14:21:18,706 INFO [STDOUT] 2008-01-23 14:21:18,706 DEBUG [at.sit.cdms.web.actions.test.AddItem] - Added item with index of 2
                    
                    2008-01-23 14:21:18,706 DEBUG [at.sit.cdms.web.actions.test.AddItem] Added item with index of 2
                    
                    2008-01-23 14:21:19,330 INFO [STDOUT] 2008-01-23 14:21:19,330 DEBUG [at.sit.cdms.web.actions.ActionFactory] - Looking for bean addItem
                    
                    2008-01-23 14:21:19,330 DEBUG [at.sit.cdms.web.actions.ActionFactory] Looking for bean addItem
                    
                    2008-01-23 14:21:19,330 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'addItem'
                    
                    2008-01-23 14:21:19,330 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-127.0.0.1-8080-1,5,jboss]
                    
                    2008-01-23 14:21:19,330 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/3)
                    
                    2008-01-23 14:21:19,330 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                    
                    2008-01-23 14:21:19,330 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:3
                    
                    2008-01-23 14:21:19,330 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:3
                    
                    2008-01-23 14:21:19,330 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                    
                    2008-01-23 14:21:19,330 INFO [STDOUT] 2008-01-23 14:21:19,330 DEBUG [at.sit.cdms.web.actions.test.AddItem] - Added item with index of 3
                    
                    2008-01-23 14:21:19,330 DEBUG [at.sit.cdms.web.actions.test.AddItem] Added item with index of 3
                    
                    2008-01-23 14:21:26,563 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[EvictionTimer-0,5,jboss]
                    
                    2008-01-23 14:21:26,563 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                    
                    2008-01-23 14:21:26,563 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:4
                    
                    2008-01-23 14:21:26,563 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:4
                    
                    2008-01-23 14:21:26,563 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                    
                    2008-01-23 14:21:26,563 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[EvictionTimer-0,5,jboss]
                    
                    2008-01-23 14:21:26,579 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                    
                    2008-01-23 14:21:26,579 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:5
                    
                    2008-01-23 14:21:26,579 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:5
                    
                    2008-01-23 14:21:26,579 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                    
                    
                    


                    I dont see any "inserts" like i normally see when in pessimistic mode!!

                    Another thing i noticed with the pessimictic log, was the number of selects going on.
                    Log looks like this for pessimistic

                    2008-01-23 13:43:10,554 DEBUG [at.sit.cdms.web.actions.ActionFactory] Looking for bean addItem
                    
                    2008-01-23 13:43:10,554 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'addItem'
                    
                    2008-01-23 13:43:10,554 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/2)
                    
                    2008-01-23 13:43:10,554 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/2)
                    
                    2008-01-23 13:43:10,554 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/2)
                    
                    2008-01-23 13:43:10,554 INFO [STDOUT] 2008-01-23 13:43:10,554 DEBUG [at.sit.cdms.web.actions.test.AddItem] - Added item with index of 2
                    
                    2008-01-23 13:43:10,554 DEBUG [at.sit.cdms.web.actions.test.AddItem] Added item with index of 2
                    
                    2008-01-23 13:43:10,554 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: insert into jbosscache (fqn, node, parent) values (?, ?, ?) (/quotes/2)
                    
                    2008-01-23 13:43:10,601 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes)
                    
                    2008-01-23 13:44:20,226 INFO [STDOUT] 2008-01-23 13:44:20,226 DEBUG [at.sit.cdms.web.actions.ActionFactory] - Looking for bean addItem
                    
                    2008-01-23 13:44:20,226 DEBUG [at.sit.cdms.web.actions.ActionFactory] Looking for bean addItem
                    
                    2008-01-23 13:44:20,226 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'addItem'
                    
                    2008-01-23 13:44:20,226 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/3)
                    
                    2008-01-23 13:44:20,226 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/3)
                    
                    2008-01-23 13:44:20,242 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/3)
                    
                    2008-01-23 13:44:20,242 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: insert into jbosscache (fqn, node, parent) values (?, ?, ?) (/quotes/3)
                    
                    2008-01-23 13:44:20,258 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes)
                    
                    2008-01-23 13:44:20,258 INFO [STDOUT] 2008-01-23 13:44:20,242 DEBUG [at.sit.cdms.web.actions.test.AddItem] - Added item with index of 3
                    
                    2008-01-23 13:44:20,242 DEBUG [at.sit.cdms.web.actions.test.AddItem] Added item with index of 3
                    
                    


                    Im seeing 3 selects and then a write, surely thats overhead!! Ok I have now seen http://jira.jboss.org/jira/browse/JBCACHE-1261. That relates to what im seeing with in pessimistic mode.

                    Any thoughts on whats going on with the OPTIMISTIC mode or am i missing the big picture??

                    Cheers,
                    LL


                    • 7. Re: Config Question
                      manik

                      I don't see any log entries pertaining to the CacheLoader and CacheStore interceptors. Could you pls enable TRACE logging for these as well?

                      • 8. Re: Config Question
                        lovelyliatroim

                        Here you go

                        2008-01-23 15:16:25,916 INFO [STDOUT] 2008-01-23 15:16:25,916 DEBUG [at.sit.cdms.web.actions.ActionFactory] - Looking for bean addItem
                        
                        2008-01-23 15:16:25,916 DEBUG [at.sit.cdms.web.actions.ActionFactory] Looking for bean addItem
                        
                        2008-01-23 15:16:25,916 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'addItem'
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _put; MethodIdInteger: 3; Args: (null, /quotes/2, image, at.sit.cache.node.DataItem@1a29afb, true)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=true, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}]
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as null and gtx as null
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _put; MethodIdInteger: 3; Args: (null, /quotes/2, image, at.sit.cache.node.DataItem@1a29afb, true)]
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.TxInterceptor] Creating transaction for thread Thread[http-127.0.0.1-8080-1,5,jboss]
                        
                        2008-01-23 15:16:25,916 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-127.0.0.1-8080-1,5,jboss]
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is null
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.CacheImpl.CMDS-Cluster] created new GTX: GlobalTransaction:<null>:2, local TX=TransactionImple < ac, BasicAction: afb9924:679:47974b77:75 status: ActionStatus.RUNNING >
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.TxInterceptor] Registering sync handler for tx TransactionImple < ac, BasicAction: afb9924:679:47974b77:75 status: ActionStatus.RUNNING >, gtx GlobalTransaction:<null>:2
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.TxInterceptor] registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:2, tx=com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple@7273602))
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] invoke MethodName: _put; MethodIdInteger: 3; Args: (GlobalTransaction:<null>:2, /quotes/2, image, at.sit.cache.node.DataItem@1a29afb, true)
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _put; MethodIdInteger: 3; Args: (GlobalTransaction:<null>:2, /quotes/2, image, at.sit.cache.node.DataItem@1a29afb, true)
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] must load, node null
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /quotes/2 mustLoad=true
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.UnversionedNode] created child: fqn=/quotes/2
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] createTempNode n VersionedNode[ /quotes/2 data=[]]
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /quotes/2
                        
                        2008-01-23 15:16:25,916 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/2)
                        
                        2008-01-23 15:16:25,916 TRACE [org.jboss.cache.loader.ManagedConnectionFactory] Connection checked out: org.jboss.resource.adapter.jdbc.jdk5.WrappedConnectionJDK5@83c235
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists false
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] Setting dataLoaded to true
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.OptimisticNodeInterceptor] Setting versioning for node /quotes/2 to implicit
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Invoking EvictionInterceptor
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Updating node/element events with no tx
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Adding event EvictedEN[fqn=/quotes/2 event=ADD_ELEMENT_EVENT diff=1] to region at /quotes
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished updating node
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished invoking EvictionInterceptor
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] Running beforeCompletion on gtx GlobalTransaction:<null>:2
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as TransactionImple < ac, BasicAction: afb9924:679:47974b77:75 status: ActionStatus.RUNNING > and gtx as GlobalTransaction:<null>:2
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] No modifications in this tx. Skipping beforeCompletion()
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as TransactionImple < ac, BasicAction: afb9924:679:47974b77:75 status: ActionStatus.COMMITTED > and gtx as GlobalTransaction:<null>:2
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] calling aftercompletion for GlobalTransaction:<null>:2
                        
                        2008-01-23 15:16:25,931 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] running commit for GlobalTransaction:<null>:2
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] invoke MethodName: commit; MethodIdInteger: 11; Args: (GlobalTransaction:<null>:2)
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] Commit called with no modifications; ignoring.
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: commit; MethodIdInteger: 11; Args: (GlobalTransaction:<null>:2)
                        
                        2008-01-23 15:16:25,931 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:2
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Merging data since node is dirty
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Versioning is implicit; incrementing.
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Setting version of node /quotes/2 from Ver=0 to Ver=1
                        
                        2008-01-23 15:16:25,931 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:2
                        
                        2008-01-23 15:16:25,931 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as null and gtx as null
                        
                        2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
                        
                        2008-01-23 15:16:25,931 INFO [STDOUT] 2008-01-23 15:16:25,931 DEBUG [at.sit.cdms.web.actions.test.AddItem] - Added item with index of 2
                        
                        2008-01-23 15:16:25,931 DEBUG [at.sit.cdms.web.actions.test.AddItem] Added item with index of 2
                        
                        2008-01-23 15:16:42,353 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] process(): region: /quotes
                        
                        2008-01-23 15:16:42,400 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Adding element /quotes/1 for a node that doesn't exist yet. Process as an add.
                        
                        2008-01-23 15:16:42,400 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Adding node /quotes/1 with 1 elements to eviction queue
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] /quotes/1 added successfully to eviction queue
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Adding element /quotes/2 for a node that doesn't exist yet. Process as an add.
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Adding node /quotes/2 with 1 elements to eviction queue
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] /quotes/2 added successfully to eviction queue
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] processed 2 node events in region: /quotes
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Recycle queue is empty
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /quotes/1 has been idle for 47ms
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /quotes/1 should not be evicted
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /quotes/1 has been idle for 47ms
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /quotes/1 should not be evicted
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /quotes/1 will be evicted because of exceeding the maxNode limit. maxNode: 1 but current queue size is: 2
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Attempting to evict cache node with fqn of /quotes/1
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _evict; MethodIdInteger: 8; Args: (/quotes/1)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}]
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as null and gtx as null
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _evict; MethodIdInteger: 8; Args: (/quotes/1)]
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] Creating transaction for thread Thread[EvictionTimer-0,5,jboss]
                        
                        2008-01-23 15:16:42,447 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[EvictionTimer-0,5,jboss]
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is null
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.CacheImpl.CMDS-Cluster] created new GTX: GlobalTransaction:<null>:3, local TX=TransactionImple < ac, BasicAction: afb9924:679:47974b77:79 status: ActionStatus.RUNNING >
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] Registering sync handler for tx TransactionImple < ac, BasicAction: afb9924:679:47974b77:79 status: ActionStatus.RUNNING >, gtx GlobalTransaction:<null>:3
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:3, tx=com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple@10900158))
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] invoke MethodName: _evict; MethodIdInteger: 8; Args: (/quotes/1)
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _evict; MethodIdInteger: 8; Args: (/quotes/1)
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.OptimisticNodeInterceptor] read Method MethodName: _evict; MethodIdInteger: 8; Args: (/quotes/1) called - Not handling, passing on.
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.CallInterceptor] Passing up method MethodName: _evict; MethodIdInteger: 8; Args: (/quotes/1) so it gets invoked on cache.
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.CacheImpl.CMDS-Cluster] _evict(/quotes/1)
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.CacheImpl.CMDS-Cluster] _remove(null, "/quotes/1", undo=false)
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Invoking EvictionInterceptor
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Updating node/element events with no tx
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished invoking EvictionInterceptor
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] Running beforeCompletion on gtx GlobalTransaction:<null>:3
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as TransactionImple < ac, BasicAction: afb9924:679:47974b77:79 status: ActionStatus.RUNNING > and gtx as GlobalTransaction:<null>:3
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] No modifications in this tx. Skipping beforeCompletion()
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as TransactionImple < ac, BasicAction: afb9924:679:47974b77:79 status: ActionStatus.COMMITTED > and gtx as GlobalTransaction:<null>:3
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] calling aftercompletion for GlobalTransaction:<null>:3
                        
                        2008-01-23 15:16:42,447 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.TxInterceptor] running commit for GlobalTransaction:<null>:3
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] invoke MethodName: commit; MethodIdInteger: 11; Args: (GlobalTransaction:<null>:3)
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] Commit called with no modifications; ignoring.
                        
                        2008-01-23 15:16:42,447 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: commit; MethodIdInteger: 11; Args: (GlobalTransaction:<null>:3)
                        
                        2008-01-23 15:16:42,447 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:3
                        
                        2008-01-23 15:16:42,463 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:3
                        
                        2008-01-23 15:16:42,463 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                        
                        2008-01-23 15:16:42,463 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:16:42,463 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as null and gtx as null
                        
                        2008-01-23 15:16:42,463 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
                        
                        2008-01-23 15:16:42,463 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Eviction of cache node with fqn of /quotes/1 successful
                        
                        2008-01-23 15:16:42,463 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] process(): region: /
                        
                        2008-01-23 15:16:42,463 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] processed 0 node events in region: /
                        
                        2008-01-23 15:16:42,463 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Recycle queue is empty
                        
                        2008-01-23 15:17:02,931 INFO [STDOUT] 2008-01-23 15:17:02,931 DEBUG [at.sit.cdms.web.actions.ActionFactory] - Looking for bean addItem
                        
                        **************Here starts next addition to tree********************
                        
                        
                        2008-01-23 15:17:02,931 DEBUG [at.sit.cdms.web.actions.ActionFactory] Looking for bean addItem
                        
                        2008-01-23 15:17:02,931 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'addItem'
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _put; MethodIdInteger: 3; Args: (null, /quotes/3, image, at.sit.cache.node.DataItem@56d15d, true)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=true, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}]
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as null and gtx as null
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _put; MethodIdInteger: 3; Args: (null, /quotes/3, image, at.sit.cache.node.DataItem@56d15d, true)]
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] Creating transaction for thread Thread[http-127.0.0.1-8080-1,5,jboss]
                        
                        2008-01-23 15:17:02,931 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-127.0.0.1-8080-1,5,jboss]
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is null
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.CacheImpl.CMDS-Cluster] created new GTX: GlobalTransaction:<null>:4, local TX=TransactionImple < ac, BasicAction: afb9924:679:47974b77:7b status: ActionStatus.RUNNING >
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] Registering sync handler for tx TransactionImple < ac, BasicAction: afb9924:679:47974b77:7b status: ActionStatus.RUNNING >, gtx GlobalTransaction:<null>:4
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:4, tx=com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple@7083822))
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] invoke MethodName: _put; MethodIdInteger: 3; Args: (GlobalTransaction:<null>:4, /quotes/3, image, at.sit.cache.node.DataItem@56d15d, true)
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _put; MethodIdInteger: 3; Args: (GlobalTransaction:<null>:4, /quotes/3, image, at.sit.cache.node.DataItem@56d15d, true)
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] must load, node null
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /quotes/3 mustLoad=true
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.UnversionedNode] created child: fqn=/quotes/3
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] createTempNode n VersionedNode[ /quotes/3 data=[]]
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /quotes/3
                        
                        2008-01-23 15:17:02,931 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/3)
                        
                        2008-01-23 15:17:02,931 TRACE [org.jboss.cache.loader.ManagedConnectionFactory] Connection checked out: org.jboss.resource.adapter.jdbc.jdk5.WrappedConnectionJDK5@65dea9
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists false
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] Setting dataLoaded to true
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.OptimisticNodeInterceptor] Setting versioning for node /quotes/3 to implicit
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Invoking EvictionInterceptor
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Updating node/element events with no tx
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Adding event EvictedEN[fqn=/quotes/3 event=ADD_ELEMENT_EVENT diff=1] to region at /quotes
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished updating node
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished invoking EvictionInterceptor
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.TxInterceptor] Running beforeCompletion on gtx GlobalTransaction:<null>:4
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as TransactionImple < ac, BasicAction: afb9924:679:47974b77:7b status: ActionStatus.RUNNING > and gtx as GlobalTransaction:<null>:4
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.TxInterceptor] No modifications in this tx. Skipping beforeCompletion()
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as TransactionImple < ac, BasicAction: afb9924:679:47974b77:7b status: ActionStatus.COMMITTED > and gtx as GlobalTransaction:<null>:4
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.TxInterceptor] calling aftercompletion for GlobalTransaction:<null>:4
                        
                        2008-01-23 15:17:02,947 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.TxInterceptor] running commit for GlobalTransaction:<null>:4
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] invoke MethodName: commit; MethodIdInteger: 11; Args: (GlobalTransaction:<null>:4)
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] Commit called with no modifications; ignoring.
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: commit; MethodIdInteger: 11; Args: (GlobalTransaction:<null>:4)
                        
                        2008-01-23 15:17:02,947 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:4
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Merging data since node is dirty
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Versioning is implicit; incrementing.
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Setting version of node /quotes/3 from Ver=0 to Ver=1
                        
                        2008-01-23 15:17:02,947 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:4
                        
                        2008-01-23 15:17:02,947 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as null and gtx as null
                        
                        2008-01-23 15:17:02,947 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
                        
                        2008-01-23 15:17:02,947 INFO [STDOUT] 2008-01-23 15:17:02,947 DEBUG [at.sit.cdms.web.actions.test.AddItem] - Added item with index of 3
                        
                        2008-01-23 15:17:02,947 DEBUG [at.sit.cdms.web.actions.test.AddItem] Added item with index of 3
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] process(): region: /quotes
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Adding element /quotes/3 for a node that doesn't exist yet. Process as an add.
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Adding node /quotes/3 with 1 elements to eviction queue
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] /quotes/3 added successfully to eviction queue
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] processed 1 node events in region: /quotes
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Recycle queue is empty
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /quotes/2 has been idle for 29906ms
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /quotes/2 should not be evicted
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /quotes/2 has been idle for 29906ms
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /quotes/2 should not be evicted
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /quotes/2 will be evicted because of exceeding the maxNode limit. maxNode: 1 but current queue size is: 2
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Attempting to evict cache node with fqn of /quotes/2
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _evict; MethodIdInteger: 8; Args: (/quotes/2)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}]
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as null and gtx as null
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _evict; MethodIdInteger: 8; Args: (/quotes/2)]
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] Creating transaction for thread Thread[EvictionTimer-0,5,jboss]
                        
                        2008-01-23 15:17:12,353 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[EvictionTimer-0,5,jboss]
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is null
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.CacheImpl.CMDS-Cluster] created new GTX: GlobalTransaction:<null>:5, local TX=TransactionImple < ac, BasicAction: afb9924:679:47974b77:7f status: ActionStatus.RUNNING >
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] Registering sync handler for tx TransactionImple < ac, BasicAction: afb9924:679:47974b77:7f status: ActionStatus.RUNNING >, gtx GlobalTransaction:<null>:5
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:5, tx=com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple@9930886))
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] invoke MethodName: _evict; MethodIdInteger: 8; Args: (/quotes/2)
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _evict; MethodIdInteger: 8; Args: (/quotes/2)
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.OptimisticNodeInterceptor] read Method MethodName: _evict; MethodIdInteger: 8; Args: (/quotes/2) called - Not handling, passing on.
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.CallInterceptor] Passing up method MethodName: _evict; MethodIdInteger: 8; Args: (/quotes/2) so it gets invoked on cache.
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.CacheImpl.CMDS-Cluster] _evict(/quotes/2)
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.CacheImpl.CMDS-Cluster] _remove(null, "/quotes/2", undo=false)
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Invoking EvictionInterceptor
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Updating node/element events with no tx
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished invoking EvictionInterceptor
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] Running beforeCompletion on gtx GlobalTransaction:<null>:5
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as TransactionImple < ac, BasicAction: afb9924:679:47974b77:7f status: ActionStatus.RUNNING > and gtx as GlobalTransaction:<null>:5
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] No modifications in this tx. Skipping beforeCompletion()
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as TransactionImple < ac, BasicAction: afb9924:679:47974b77:7f status: ActionStatus.COMMITTED > and gtx as GlobalTransaction:<null>:5
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] calling aftercompletion for GlobalTransaction:<null>:5
                        
                        2008-01-23 15:17:12,353 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] running commit for GlobalTransaction:<null>:5
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] invoke MethodName: commit; MethodIdInteger: 11; Args: (GlobalTransaction:<null>:5)
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] Commit called with no modifications; ignoring.
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: commit; MethodIdInteger: 11; Args: (GlobalTransaction:<null>:5)
                        
                        2008-01-23 15:17:12,353 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:5
                        
                        2008-01-23 15:17:12,353 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:5
                        
                        2008-01-23 15:17:12,353 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                        
                        2008-01-23 15:17:12,353 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                        
                        2008-01-23 15:17:12,369 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as null and gtx as null
                        
                        2008-01-23 15:17:12,369 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
                        
                        2008-01-23 15:17:12,369 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Eviction of cache node with fqn of /quotes/2 successful
                        
                        2008-01-23 15:17:12,369 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] process(): region: /
                        
                        2008-01-23 15:17:12,369 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] processed 0 node events in region: /
                        
                        2008-01-23 15:17:12,369 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Recycle queue is empty
                        




                        • 9. Re: Config Question
                          manik

                          Hmm, this is the interesting bit:

                          2008-01-23 15:16:25,931 TRACE [org.jboss.cache.interceptors.TxInterceptor] No modifications in this tx. Skipping beforeCompletion()
                          


                          here clearly has been a modification. Not that I recommend this in production, but to help debug, could you try the same with using the DummyTransactionManagerLookup instead of the GenericTransactionManagerLookup and let me know what happens?

                          • 10. Re: Config Question
                            manik

                            Hmm, just tried running OptimisticWithCacheLoaderTest#testCacheStoringImplicitTx() with JBoss-JTA (Arjuna's TM) instead of the DummyTM and it works fine.

                            Could you enable TRACE logging on all interceptors?

                            • 11. Re: Config Question
                              lovelyliatroim

                              Ok tried the Dummy Transaction manager and same story, its in the memory of the cache but not in the DB.

                              Log is as follows

                              2008-01-24 15:59:05,586 INFO [STDOUT] 2008-01-24 15:59:05,586 DEBUG [at.sit.cdms.web.actions.ActionFactory] - Looking for bean addItem
                              
                              2008-01-24 15:59:05,586 DEBUG [at.sit.cdms.web.actions.ActionFactory] Looking for bean addItem
                              
                              2008-01-24 15:59:05,586 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'addItem'
                              
                              2008-01-24 15:59:05,586 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-127.0.0.1-8080-1,5,jboss]
                              
                              2008-01-24 15:59:05,586 DEBUG [org.jboss.cache.transaction.DummyTransaction] registering synchronization handler tx=org.jboss.cache.transaction.DummyTransaction@8634933, handlers=[]
                              
                              2008-01-24 15:59:05,586 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/2)
                              
                              2008-01-24 15:59:05,586 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing beforeCompletion for tx=org.jboss.cache.transaction.DummyTransaction@8634933, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:2, tx=org.jboss.cache.transaction.DummyTransaction@8634933)]
                              
                              2008-01-24 15:59:05,586 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing afterCompletion for tx=org.jboss.cache.transaction.DummyTransaction@8634933, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:2, tx=org.jboss.cache.transaction.DummyTransaction@8634933)]
                              
                              2008-01-24 15:59:05,586 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                              
                              2008-01-24 15:59:05,586 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:2
                              
                              2008-01-24 15:59:05,586 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:2
                              
                              2008-01-24 15:59:05,586 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                              
                              2008-01-24 15:59:05,586 INFO [STDOUT] 2008-01-24 15:59:05,586 DEBUG [at.sit.cdms.web.actions.test.AddItem] - Added item with index of 2
                              
                              2008-01-24 15:59:05,586 DEBUG [at.sit.cdms.web.actions.test.AddItem] Added item with index of 2
                              
                              2008-01-24 15:59:06,477 INFO [STDOUT] 2008-01-24 15:59:06,477 DEBUG [at.sit.cdms.web.actions.ActionFactory] - Looking for bean addItem
                              
                              2008-01-24 15:59:06,477 DEBUG [at.sit.cdms.web.actions.ActionFactory] Looking for bean addItem
                              
                              2008-01-24 15:59:06,477 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'addItem'
                              
                              2008-01-24 15:59:06,477 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-127.0.0.1-8080-1,5,jboss]
                              
                              2008-01-24 15:59:06,477 DEBUG [org.jboss.cache.transaction.DummyTransaction] registering synchronization handler tx=org.jboss.cache.transaction.DummyTransaction@32573099, handlers=[]
                              
                              2008-01-24 15:59:06,477 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/3)
                              
                              2008-01-24 15:59:06,493 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing beforeCompletion for tx=org.jboss.cache.transaction.DummyTransaction@32573099, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:3, tx=org.jboss.cache.transaction.DummyTransaction@32573099)]
                              
                              2008-01-24 15:59:06,493 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing afterCompletion for tx=org.jboss.cache.transaction.DummyTransaction@32573099, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:3, tx=org.jboss.cache.transaction.DummyTransaction@32573099)]
                              
                              2008-01-24 15:59:06,493 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                              
                              2008-01-24 15:59:06,493 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:3
                              
                              2008-01-24 15:59:06,493 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:3
                              
                              2008-01-24 15:59:06,493 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                              
                              2008-01-24 15:59:06,493 INFO [STDOUT] 2008-01-24 15:59:06,493 DEBUG [at.sit.cdms.web.actions.test.AddItem] - Added item with index of 3
                              
                              2008-01-24 15:59:06,493 DEBUG [at.sit.cdms.web.actions.test.AddItem] Added item with index of 3
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[EvictionTimer-0,5,jboss]
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.transaction.DummyTransaction] registering synchronization handler tx=org.jboss.cache.transaction.DummyTransaction@16702321, handlers=[]
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing beforeCompletion for tx=org.jboss.cache.transaction.DummyTransaction@16702321, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:4, tx=org.jboss.cache.transaction.DummyTransaction@16702321)]
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing afterCompletion for tx=org.jboss.cache.transaction.DummyTransaction@16702321, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:4, tx=org.jboss.cache.transaction.DummyTransaction@16702321)]
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:4
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:4
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[EvictionTimer-0,5,jboss]
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.transaction.DummyTransaction] registering synchronization handler tx=org.jboss.cache.transaction.DummyTransaction@33097577, handlers=[]
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing beforeCompletion for tx=org.jboss.cache.transaction.DummyTransaction@33097577, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:5, tx=org.jboss.cache.transaction.DummyTransaction@33097577)]
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing afterCompletion for tx=org.jboss.cache.transaction.DummyTransaction@33097577, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:5, tx=org.jboss.cache.transaction.DummyTransaction@33097577)]
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:5
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:5
                              
                              2008-01-24 15:59:21,930 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                              


                              • 12. Re: Config Question
                                lovelyliatroim

                                Sorry didnt have trace on with that last one, here it is with trace on

                                2008-01-24 16:12:02,352 INFO [STDOUT] 2008-01-24 16:12:02,352 DEBUG [at.sit.cdms.web.actions.ActionFactory] - Looking for bean addItem
                                
                                2008-01-24 16:12:02,352 DEBUG [at.sit.cdms.web.actions.ActionFactory] Looking for bean addItem
                                
                                2008-01-24 16:12:02,352 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'addItem'
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _put; MethodIdInteger: 3; Args: (null, /quotes/2, quote, at.sit.cache.node.DataItem@1c2fdde, true)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=true, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as null and gtx as null
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _put; MethodIdInteger: 3; Args: (null, /quotes/2, quote, at.sit.cache.node.DataItem@1c2fdde, true)]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] Creating transaction for thread Thread[http-127.0.0.1-8080-1,5,jboss]
                                
                                2008-01-24 16:12:02,352 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-127.0.0.1-8080-1,5,jboss]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is null
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.CacheImpl.CMDS-Cluster] created new GTX: GlobalTransaction:<null>:2, local TX=org.jboss.cache.transaction.DummyTransaction@a920ad
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] Registering sync handler for tx org.jboss.cache.transaction.DummyTransaction@a920ad, gtx GlobalTransaction:<null>:2
                                
                                2008-01-24 16:12:02,352 DEBUG [org.jboss.cache.transaction.DummyTransaction] registering synchronization handler tx=org.jboss.cache.transaction.DummyTransaction@11083949, handlers=[]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:2, tx=org.jboss.cache.transaction.DummyTransaction@11083949))
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] invoke MethodName: _put; MethodIdInteger: 3; Args: (GlobalTransaction:<null>:2, /quotes/2, quote, at.sit.cache.node.DataItem@1c2fdde, true)
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _put; MethodIdInteger: 3; Args: (GlobalTransaction:<null>:2, /quotes/2, quote, at.sit.cache.node.DataItem@1c2fdde, true)
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] must load, node null
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /quotes/2 mustLoad=true
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.UnversionedNode] created child: fqn=/quotes/2
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] createTempNode n VersionedNode[ /quotes/2 data=[]]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /quotes/2
                                
                                2008-01-24 16:12:02,352 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/2)
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying ManagedConnection from pool: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@e55d75[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f handles=0 lastUse=1201187519899 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@1769f17 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@c6af24 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1c1e949 txSync=null]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@e55d75[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f handles=0 lastUse=1201187519899 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@1769f17 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@c6af24 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1c1e949 txSync=null] [InUse/Available/Max]: [1/9/10]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] No transaction, no need to enlist: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@e55d75[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f handles=0 lastUse=1201187519899 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@1769f17 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@c6af24 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1c1e949 txSync=null]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.loader.ManagedConnectionFactory] Connection checked out: org.jboss.resource.adapter.jdbc.jdk5.WrappedConnectionJDK5@1a0769d
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] connectionClosed called mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] unregisterConnection: 0 handles left
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] isManagedConnectionFree=true mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] delisting org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@e55d75[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f handles=0 lastUse=1201187519899 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@1769f17 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@c6af24 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1c1e949 txSync=null]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@e55d75[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f handles=0 lastUse=1201187519899 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@1769f17 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@c6af24 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1c1e949 txSync=null]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@e55d75[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f handles=0 lastUse=1201187522352 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@1769f17 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@c6af24 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1c1e949 txSync=null] [InUse/Available/Max]: [0/10/10]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists false
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] Setting dataLoaded to true
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.OptimisticNodeInterceptor] Setting versioning for node /quotes/2 to implicit
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Invoking EvictionInterceptor
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Updating node/element events with no tx
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Adding event EvictedEN[fqn=/quotes/2 event=ADD_ELEMENT_EVENT diff=1] to region at /quotes
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished updating node
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished invoking EvictionInterceptor
                                
                                2008-01-24 16:12:02,352 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing beforeCompletion for tx=org.jboss.cache.transaction.DummyTransaction@11083949, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:2, tx=org.jboss.cache.transaction.DummyTransaction@11083949)]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] Running beforeCompletion on gtx GlobalTransaction:<null>:2
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as org.jboss.cache.transaction.DummyTransaction@a920ad and gtx as GlobalTransaction:<null>:2
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] No modifications in this tx. Skipping beforeCompletion()
                                
                                2008-01-24 16:12:02,352 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing afterCompletion for tx=org.jboss.cache.transaction.DummyTransaction@11083949, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:2, tx=org.jboss.cache.transaction.DummyTransaction@11083949)]
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as org.jboss.cache.transaction.DummyTransaction@a920ad and gtx as GlobalTransaction:<null>:2
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] calling aftercompletion for GlobalTransaction:<null>:2
                                
                                2008-01-24 16:12:02,352 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] running commit for GlobalTransaction:<null>:2
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] invoke MethodName: commit; MethodIdInteger: 11; Args: (GlobalTransaction:<null>:2)
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] Commit called with no modifications; ignoring.
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: commit; MethodIdInteger: 11; Args: (GlobalTransaction:<null>:2)
                                
                                2008-01-24 16:12:02,352 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:2
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Merging data since node is dirty
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Versioning is implicit; incrementing.
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Setting version of node /quotes/2 from Ver=0 to Ver=1
                                
                                2008-01-24 16:12:02,352 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:2
                                
                                2008-01-24 16:12:02,352 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as null and gtx as null
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
                                
                                2008-01-24 16:12:02,352 INFO [STDOUT] 2008-01-24 16:12:02,352 DEBUG [at.sit.cdms.web.actions.test.AddItem] - Added item with index of 2
                                
                                2008-01-24 16:12:02,352 DEBUG [at.sit.cdms.web.actions.test.AddItem] Added item with index of 2
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.web.tomcat.security.SecurityAssociationValve] End invoke, callernull
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:null
                                
                                2008-01-24 16:12:02,352 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:null
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] filter name=org.jboss.security.plugins.JBossSecurityContext, exclude=false
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] findClass(org.jboss.security.plugins.JBossSecurityContext) called
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@712a2e{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/cmds.ear/ ,addedOrder=16} name=org.jboss.security.plugins.JBossSecurityContext, loadClassDepth=0
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.mx.loading.RepositoryClassLoader] Loaded class from cache, org.jboss.security.plugins.JBossSecurityContext@10878fe<CodeSource: (vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/lib/jbosssx.jar <no signer certificates>)>
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@712a2e{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/cmds.ear/ ,addedOrder=16} name=org.jboss.security.plugins.JBossSecurityContext class=class org.jboss.security.plugins.JBossSecurityContext cl=org.jboss.mx.loading.UnifiedClassLoader3@ef9525{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/conf/jboss-service.xml ,addedOrder=2}
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] filter name=org.jboss.security.plugins.JBossSecurityContextUtil, exclude=false
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] findClass(org.jboss.security.plugins.JBossSecurityContextUtil) called
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@712a2e{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/cmds.ear/ ,addedOrder=16} name=org.jboss.security.plugins.JBossSecurityContextUtil, loadClassDepth=0
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.mx.loading.RepositoryClassLoader] Loaded class from cache, org.jboss.security.plugins.JBossSecurityContextUtil@c76887<CodeSource: (vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/lib/jbosssx.jar <no signer certificates>)>
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@712a2e{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/cmds.ear/ ,addedOrder=16} name=org.jboss.security.plugins.JBossSecurityContextUtil class=class org.jboss.security.plugins.JBossSecurityContextUtil cl=org.jboss.mx.loading.UnifiedClassLoader3@ef9525{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/conf/jboss-service.xml ,addedOrder=2}
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:null
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.web.tomcat.security.SecurityAssociationValve] Begin invoke, callernull
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                
                                2008-01-24 16:12:03,165 INFO [STDOUT] 2008-01-24 16:12:03,165 DEBUG [at.sit.cdms.web.actions.ActionFactory] - Looking for bean addItem
                                
                                2008-01-24 16:12:03,165 DEBUG [at.sit.cdms.web.actions.ActionFactory] Looking for bean addItem
                                
                                2008-01-24 16:12:03,165 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'addItem'
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _put; MethodIdInteger: 3; Args: (null, /quotes/3, image, at.sit.cache.node.DataItem@50179b, true)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=true, dataVersion=null, suppressLocking=false, forceDataGravitation=false, skipDataGravitation=false}, originLocal=true, txHasMods=false}]
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as null and gtx as null
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [MethodName: _put; MethodIdInteger: 3; Args: (null, /quotes/3, image, at.sit.cache.node.DataItem@50179b, true)]
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.TxInterceptor] Creating transaction for thread Thread[http-127.0.0.1-8080-1,5,jboss]
                                
                                2008-01-24 16:12:03,165 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-127.0.0.1-8080-1,5,jboss]
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is null
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.CacheImpl.CMDS-Cluster] created new GTX: GlobalTransaction:<null>:3, local TX=org.jboss.cache.transaction.DummyTransaction@3dc560
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.TxInterceptor] Registering sync handler for tx org.jboss.cache.transaction.DummyTransaction@3dc560, gtx GlobalTransaction:<null>:3
                                
                                2008-01-24 16:12:03,165 DEBUG [org.jboss.cache.transaction.DummyTransaction] registering synchronization handler tx=org.jboss.cache.transaction.DummyTransaction@4048224, handlers=[]
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.TxInterceptor] registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:3, tx=org.jboss.cache.transaction.DummyTransaction@4048224))
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] invoke MethodName: _put; MethodIdInteger: 3; Args: (GlobalTransaction:<null>:3, /quotes/3, image, at.sit.cache.node.DataItem@50179b, true)
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: _put; MethodIdInteger: 3; Args: (GlobalTransaction:<null>:3, /quotes/3, image, at.sit.cache.node.DataItem@50179b, true)
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] must load, node null
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /quotes/3 mustLoad=true
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.UnversionedNode] created child: fqn=/quotes/3
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] createTempNode n VersionedNode[ /quotes/3 data=[]]
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /quotes/3
                                
                                2008-01-24 16:12:03,165 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/3)
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying ManagedConnection from pool: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@e55d75[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f handles=0 lastUse=1201187522352 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@1769f17 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@c6af24 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1c1e949 txSync=null]
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@e55d75[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f handles=0 lastUse=1201187522352 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@1769f17 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@c6af24 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1c1e949 txSync=null] [InUse/Available/Max]: [1/9/10]
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] No transaction, no need to enlist: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@e55d75[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f handles=0 lastUse=1201187522352 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@1769f17 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@c6af24 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1c1e949 txSync=null]
                                
                                2008-01-24 16:12:03,165 TRACE [org.jboss.cache.loader.ManagedConnectionFactory] Connection checked out: org.jboss.resource.adapter.jdbc.jdk5.WrappedConnectionJDK5@1694399
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] connectionClosed called mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] unregisterConnection: 0 handles left
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] isManagedConnectionFree=true mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] delisting org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@e55d75[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f handles=0 lastUse=1201187522352 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@1769f17 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@c6af24 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1c1e949 txSync=null]
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@e55d75[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f handles=0 lastUse=1201187522352 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@1769f17 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@c6af24 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1c1e949 txSync=null]
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@e55d75[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@5abf3f handles=0 lastUse=1201187523180 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@1769f17 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@c6af24 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@1c1e949 txSync=null] [InUse/Available/Max]: [0/10/10]
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists false
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] Setting dataLoaded to true
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.OptimisticNodeInterceptor] Setting versioning for node /quotes/3 to implicit
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Invoking EvictionInterceptor
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Updating node/element events with no tx
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Adding event EvictedEN[fqn=/quotes/3 event=ADD_ELEMENT_EVENT diff=1] to region at /quotes
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished updating node
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished invoking EvictionInterceptor
                                
                                2008-01-24 16:12:03,180 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing beforeCompletion for tx=org.jboss.cache.transaction.DummyTransaction@4048224, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:3, tx=org.jboss.cache.transaction.DummyTransaction@4048224)]
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.TxInterceptor] Running beforeCompletion on gtx GlobalTransaction:<null>:3
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as org.jboss.cache.transaction.DummyTransaction@3dc560 and gtx as GlobalTransaction:<null>:3
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.TxInterceptor] No modifications in this tx. Skipping beforeCompletion()
                                
                                2008-01-24 16:12:03,180 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing afterCompletion for tx=org.jboss.cache.transaction.DummyTransaction@4048224, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:3, tx=org.jboss.cache.transaction.DummyTransaction@4048224)]
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as org.jboss.cache.transaction.DummyTransaction@3dc560 and gtx as GlobalTransaction:<null>:3
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.TxInterceptor] calling aftercompletion for GlobalTransaction:<null>:3
                                
                                2008-01-24 16:12:03,180 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.TxInterceptor] running commit for GlobalTransaction:<null>:3
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] invoke MethodName: commit; MethodIdInteger: 11; Args: (GlobalTransaction:<null>:3)
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] Commit called with no modifications; ignoring.
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] invoke MethodName: commit; MethodIdInteger: 11; Args: (GlobalTransaction:<null>:3)
                                
                                2008-01-24 16:12:03,180 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:3
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Merging data since node is dirty
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Versioning is implicit; incrementing.
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Setting version of node /quotes/3 from Ver=0 to Ver=1
                                
                                2008-01-24 16:12:03,180 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:3
                                
                                2008-01-24 16:12:03,180 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as null and gtx as null
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
                                
                                2008-01-24 16:12:03,180 INFO [STDOUT] 2008-01-24 16:12:03,180 DEBUG [at.sit.cdms.web.actions.test.AddItem] - Added item with index of 3
                                
                                2008-01-24 16:12:03,180 DEBUG [at.sit.cdms.web.actions.test.AddItem] Added item with index of 3
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.web.tomcat.security.SecurityAssociationValve] End invoke, callernull
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:null
                                
                                2008-01-24 16:12:03,180 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:null
                                
                                2008-01-24 16:12:07,196 TRACE [org.jboss.system.server.profileservice.hotdeploy.HDScanner] Begin deployment scan
                                
                                2008-01-24 16:12:07,196 TRACE [org.jboss.system.server.profile.basic.ProfileImpl] Checking applications for modifications
                                
                                2008-01-24 16:12:07,211 TRACE [org.jboss.system.server.profileservice.hotdeploy.HDScanner] End deployment scan
                                
                                2008-01-24 16:12:09,383 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] subject: null
                                
                                2008-01-24 16:12:09,383 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] getManagedConnection trackByTx=true tx=null
                                
                                2008-01-24 16:12:09,383 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying ManagedConnection from pool: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@90da40[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d handles=0 lastUse=1201187499540 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@1b82f66 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1496354 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@118424f txSync=null]
                                
                                2008-01-24 16:12:09,383 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@90da40[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d handles=0 lastUse=1201187499540 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@1b82f66 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1496354 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@118424f txSync=null] [InUse/Available/Max]: [1/19/20]
                                
                                2008-01-24 16:12:09,383 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] No transaction, no need to enlist: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@90da40[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d handles=0 lastUse=1201187499540 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@1b82f66 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1496354 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@118424f txSync=null]
                                
                                2008-01-24 16:12:09,383 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] connectionClosed called mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d
                                
                                2008-01-24 16:12:09,383 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] unregisterConnection: 0 handles left
                                
                                2008-01-24 16:12:09,383 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] isManagedConnectionFree=true mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d
                                
                                2008-01-24 16:12:09,383 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] delisting org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@90da40[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d handles=0 lastUse=1201187499540 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@1b82f66 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1496354 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@118424f txSync=null]
                                
                                2008-01-24 16:12:09,383 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@90da40[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d handles=0 lastUse=1201187499540 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@1b82f66 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1496354 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@118424f txSync=null]
                                
                                2008-01-24 16:12:09,383 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@90da40[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d handles=0 lastUse=1201187529383 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@1b82f66 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1496354 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@118424f txSync=null] [InUse/Available/Max]: [0/20/20]
                                
                                2008-01-24 16:12:12,211 TRACE [org.jboss.system.server.profileservice.hotdeploy.HDScanner] Begin deployment scan
                                
                                2008-01-24 16:12:12,211 TRACE [org.jboss.system.server.profile.basic.ProfileImpl] Checking applications for modifications
                                
                                2008-01-24 16:12:12,243 TRACE [org.jboss.system.server.profileservice.hotdeploy.HDScanner] End deployment scan
                                
                                2008-01-24 16:12:17,211 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] subject: null
                                
                                2008-01-24 16:12:17,211 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] getManagedConnection trackByTx=true tx=null
                                
                                2008-01-24 16:12:17,211 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying ManagedConnection from pool: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@90da40[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d handles=0 lastUse=1201187529383 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@1b82f66 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1496354 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@118424f txSync=null]
                                
                                2008-01-24 16:12:17,211 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@90da40[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d handles=0 lastUse=1201187529383 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@1b82f66 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1496354 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@118424f txSync=null] [InUse/Available/Max]: [1/19/20]
                                
                                2008-01-24 16:12:17,211 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] No transaction, no need to enlist: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@90da40[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d handles=0 lastUse=1201187529383 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@1b82f66 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1496354 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@118424f txSync=null]
                                
                                2008-01-24 16:12:17,211 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] connectionClosed called mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d
                                
                                2008-01-24 16:12:17,211 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] unregisterConnection: 0 handles left
                                
                                2008-01-24 16:12:17,211 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] isManagedConnectionFree=true mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d
                                
                                2008-01-24 16:12:17,211 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] delisting org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@90da40[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d handles=0 lastUse=1201187529383 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@1b82f66 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1496354 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@118424f txSync=null]
                                
                                2008-01-24 16:12:17,211 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@90da40[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d handles=0 lastUse=1201187529383 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@1b82f66 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1496354 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@118424f txSync=null]
                                
                                2008-01-24 16:12:17,211 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@90da40[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1c6988d handles=0 lastUse=1201187537211 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@1b82f66 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1496354 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@118424f txSync=null] [InUse/Available/Max]: [0/20/20]
                                
                                2008-01-24 16:12:17,243 TRACE [org.jboss.system.server.profileservice.hotdeploy.HDScanner] Begin deployment scan
                                
                                2008-01-24 16:12:17,243 TRACE [org.jboss.system.server.profile.basic.ProfileImpl] Checking applications for modifications
                                
                                2008-01-24 16:12:17,258 TRACE [org.jboss.system.server.profileservice.hotdeploy.HDScanner] End deployment scan
                                
                                


                                • 13. Re: Config Question
                                  manik

                                  Hmm - have you tried this with 2.1.0.CR3 as well?

                                  • 14. Re: Config Question
                                    lovelyliatroim

                                     


                                    Hmm - have you tried this with 2.1.0.CR3 as well?

                                    No I havent but i have now!!

                                    Had some issues getting the 2.1.0.CR3 to work in JBoss AS 5.0 Beta3. First off the binary lib jboss-cachecore.jar in the meta-inf directory contains all -service.xml files, so JBoss AS picks this up and tries to deploy them and fails in doing so. Removed the -service files and re-jared the jboss-cachecore.jar without -service files.

                                    Cache starts up but i have a few cache related exceptions along the way


                                    11:34:15,854 ERROR [AbstractKernelController] Error installing to Instantiated: name=cache state=Described
                                    java.lang.IllegalAccessException: Class org.jboss.reflect.plugins.introspection.ReflectionUtils can not access a member of class org.jboss.cache.CacheImpl with modifiers "protected"
                                     at sun.reflect.Reflection.ensureMemberAccess(Reflection.java:65)
                                     at java.lang.reflect.Constructor.newInstance(Constructor.java:486)
                                     at org.jboss.reflect.plugins.introspection.ReflectionUtils.newInstance(ReflectionUtils.java:137)
                                     at org.jboss.reflect.plugins.introspection.ReflectConstructorInfoImpl.newInstance(ReflectConstructorInfoImpl.java:106)
                                     at org.jboss.joinpoint.plugins.BasicConstructorJoinPoint.dispatch(BasicConstructorJoinPoint.java:80)
                                     at org.jboss.aop.microcontainer.integration.AOPConstructorJoinpoint.createTarget(AOPConstructorJoinpoint.java:186)
                                     at org.jboss.aop.microcontainer.integration.AOPConstructorJoinpoint.dispatch(AOPConstructorJoinpoint.java:80)
                                     at org.jboss.kernel.plugins.dependency.KernelControllerContextAction$JoinpointDispatchWrapper.execute(KernelControllerContextAction.java:214)
                                     at org.jboss.kernel.plugins.dependency.ExecutionWrapper.execute(ExecutionWrapper.java:45)
                                     at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.dispatchExecutionWrapper(KernelControllerContextAction.java:108)
                                     at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.dispatchJoinPoint(KernelControllerContextAction.java:69)
                                     at org.jboss.kernel.plugins.dependency.InstantiateAction.installActionInternal(InstantiateAction.java:53)
                                     at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.installAction(KernelControllerContextAction.java:135)
                                     at org.jboss.kernel.plugins.dependency.KernelControllerContextAction.installAction(KernelControllerContextAction.java:46)
                                     at org.jboss.dependency.plugins.action.SimpleControllerContextAction.simpleInstallAction(SimpleControllerContextAction.java:62)
                                     at org.jboss.dependency.plugins.action.AccessControllerContextAction.install(AccessControllerContextAction.java:71)
                                     at org.jboss.dependency.plugins.AbstractControllerContextActions.install(AbstractControllerContextActions.java:51)
                                     at org.jboss.dependency.plugins.AbstractControllerContext.install(AbstractControllerContext.java:327)
                                     at org.jboss.dependency.plugins.AbstractController.install(AbstractController.java:1309)
                                     at org.jboss.dependency.plugins.AbstractController.incrementState(AbstractController.java:734)
                                     at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:862)
                                     at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:784)
                                     at org.jboss.dependency.plugins.AbstractController.install(AbstractController.java:574)
                                     at org.jboss.dependency.plugins.AbstractController.install(AbstractController.java:398)
                                     at org.jboss.deployers.vfs.deployer.kernel.BeanMetaDataDeployer.deploy(BeanMetaDataDeployer.java:69)
                                     at org.jboss.deployers.vfs.deployer.kernel.BeanMetaDataDeployer.deploy(BeanMetaDataDeployer.java:42)
                                     at org.jboss.deployers.spi.deployer.helpers.AbstractSimpleRealDeployer.internalDeploy(AbstractSimpleRealDeployer.java:65)
                                     at org.jboss.deployers.spi.deployer.helpers.AbstractRealDeployer.deploy(AbstractRealDeployer.java:50)
                                     at org.jboss.deployers.plugins.deployers.DeployerWrapper.deploy(DeployerWrapper.java:169)
                                     at org.jboss.deployers.plugins.deployers.DeployersImpl.doInstallParentFirst(DeployersImpl.java:853)
                                     at org.jboss.deployers.plugins.deployers.DeployersImpl.doInstallParentFirst(DeployersImpl.java:874)
                                     at org.jboss.deployers.plugins.deployers.DeployersImpl.doInstallParentFirst(DeployersImpl.java:906)
                                     at org.jboss.deployers.plugins.deployers.DeployersImpl.doInstallParentFirst(DeployersImpl.java:906)
                                     at org.jboss.deployers.plugins.deployers.DeployersImpl.doInstallParentFirst(DeployersImpl.java:906)
                                     at org.jboss.deployers.plugins.deployers.DeployersImpl.install(DeployersImpl.java:794)
                                     at org.jboss.dependency.plugins.AbstractControllerContext.install(AbstractControllerContext.java:327)
                                     at org.jboss.dependency.plugins.AbstractController.install(AbstractController.java:1309)
                                     at org.jboss.dependency.plugins.AbstractController.incrementState(AbstractController.java:734)
                                     at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:862)
                                     at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:784)
                                     at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:622)
                                     at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:411)
                                     at org.jboss.deployers.plugins.deployers.DeployersImpl.process(DeployersImpl.java:498)
                                     at org.jboss.deployers.plugins.main.MainDeployerImpl.process(MainDeployerImpl.java:506)
                                     at org.jboss.system.server.profileservice.ProfileServiceBootstrap.loadProfile(ProfileServiceBootstrap.java:245)
                                     at org.jboss.system.server.profileservice.ProfileServiceBootstrap.start(ProfileServiceBootstrap.java:131)
                                     at org.jboss.bootstrap.AbstractServerImpl.start(AbstractServerImpl.java:408)
                                     at org.jboss.Main.boot(Main.java:208)
                                     at org.jboss.Main$1.run(Main.java:534)
                                     at java.lang.Thread.run(Thread.java:595)
                                    


                                    Anyways cache starts up and im able to make add entries to the cache but it still doesnt write to the DB. Im using the DummyTransactionManager still.

                                    Log looks like so
                                    2008-01-25 11:38:16,616 INFO [STDOUT] 2008-01-25 11:38:16,616 DEBUG [at.sit.cdms.web.actions.ActionFactory] - Looking for bean addItem
                                    
                                    2008-01-25 11:38:16,616 DEBUG [at.sit.cdms.web.actions.ActionFactory] Looking for bean addItem
                                    
                                    2008-01-25 11:38:16,616 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'addItem'
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = null ...)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=true, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false}, originLocal=true, txHasMods=false}]
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as null and gtx as null
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.CacheMgmtInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = null ...)
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.TxInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = null ...)
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.TxInterceptor] Creating transaction for thread Thread[http-127.0.0.1-8080-1,5,jboss]
                                    
                                    2008-01-25 11:38:16,616 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-127.0.0.1-8080-1,5,jboss]
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is null
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.CacheImpl.CMDS-Cluster] created new GTX: GlobalTransaction:<null>:2, local TX=org.jboss.cache.transaction.DummyTransaction@9aee72
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.TxInterceptor] Registering sync handler for tx org.jboss.cache.transaction.DummyTransaction@9aee72, gtx GlobalTransaction:<null>:2
                                    
                                    2008-01-25 11:38:16,616 DEBUG [org.jboss.cache.transaction.DummyTransaction] registering synchronization handler tx=org.jboss.cache.transaction.DummyTransaction@10153586, handlers=[]
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.TxInterceptor] registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:2, tx=org.jboss.cache.transaction.DummyTransaction@10153586))
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.NotificationInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:2 ...)
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.NotificationInterceptor] Not registered for any handlers, passing up the chain.
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:2 ...)
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:2 ...)
                                    
                                    2008-01-25 11:38:16,616 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] must load, node null
                                    
                                    2008-01-25 11:38:16,632 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /quotes/2 mustLoad=true
                                    
                                    2008-01-25 11:38:16,632 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] createTempNode n org.jboss.cache.invocation.NodeInvocationDelegate@19c9b66
                                    
                                    2008-01-25 11:38:16,632 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /quotes/2
                                    
                                    2008-01-25 11:38:16,632 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/2)
                                    
                                    2008-01-25 11:38:16,632 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying ManagedConnection from pool: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@aa045f[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113 handles=0 lastUse=1201257420633 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@16c73b1 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@11f80c3 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@13e9853 txSync=null]
                                    
                                    2008-01-25 11:38:16,632 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@aa045f[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113 handles=0 lastUse=1201257420633 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@16c73b1 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@11f80c3 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@13e9853 txSync=null] [InUse/Available/Max]: [1/9/10]
                                    
                                    2008-01-25 11:38:16,632 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] No transaction, no need to enlist: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@aa045f[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113 handles=0 lastUse=1201257420633 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@16c73b1 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@11f80c3 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@13e9853 txSync=null]
                                    
                                    2008-01-25 11:38:16,632 TRACE [org.jboss.cache.loader.ManagedConnectionFactory] Connection checked out: org.jboss.resource.adapter.jdbc.jdk5.WrappedConnectionJDK5@9e6837
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] connectionClosed called mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] unregisterConnection: 0 handles left
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] isManagedConnectionFree=true mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] delisting org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@aa045f[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113 handles=0 lastUse=1201257420633 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@16c73b1 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@11f80c3 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@13e9853 txSync=null]
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@aa045f[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113 handles=0 lastUse=1201257420633 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@16c73b1 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@11f80c3 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@13e9853 txSync=null]
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@aa045f[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113 handles=0 lastUse=1201257496757 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@16c73b1 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@11f80c3 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@13e9853 txSync=null] [InUse/Available/Max]: [0/10/10]
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists false
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] Setting dataLoaded to true
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.cache.interceptors.OptimisticLockingInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:2 ...)
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.cache.interceptors.OptimisticLockingInterceptor] Not registered for any handlers, passing up the chain.
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:2 ...)
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Not registered for any handlers, passing up the chain.
                                    
                                    2008-01-25 11:38:16,757 TRACE [org.jboss.cache.interceptors.OptimisticCreateIfNotExistsInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:2 ...)
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:2 ...)
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.OptimisticNodeInterceptor] Setting versioning for node /quotes/2 to implicit
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.RegionManager] Contents of RegionsRegistry: {/=RegionImpl{fqn=/; classloader=null; status=ACTIVE; eviction=true; timerThreadRegistered=true}, /quotes=RegionImpl{fqn=/quotes; classloader=null; status=ACTIVE; eviction=true; timerThreadRegistered=true}}
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.RegionManager] Trying next region /quotes and got RegionImpl{fqn=/quotes; classloader=null; status=ACTIVE; eviction=true; timerThreadRegistered=true}
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.RegionManager] Contents of RegionsRegistry: {/=RegionImpl{fqn=/; classloader=null; status=ACTIVE; eviction=true; timerThreadRegistered=true}, /quotes=RegionImpl{fqn=/quotes; classloader=null; status=ACTIVE; eviction=true; timerThreadRegistered=true}}
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.RegionManager] Trying next region /quotes and got RegionImpl{fqn=/quotes; classloader=null; status=ACTIVE; eviction=true; timerThreadRegistered=true}
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Adding event EvictedEN[fqn=/quotes/2 event=ADD_ELEMENT_EVENT diff=1] to region at /quotes
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished updating node
                                    
                                    2008-01-25 11:38:16,773 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing beforeCompletion for tx=org.jboss.cache.transaction.DummyTransaction@10153586, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:2, tx=org.jboss.cache.transaction.DummyTransaction@10153586)]
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.TxInterceptor] Running beforeCompletion on gtx GlobalTransaction:<null>:2
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as org.jboss.cache.transaction.DummyTransaction@9aee72 and gtx as GlobalTransaction:<null>:2
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.TxInterceptor] No modifications in this tx. Skipping beforeCompletion()
                                    
                                    2008-01-25 11:38:16,773 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing afterCompletion for tx=org.jboss.cache.transaction.DummyTransaction@10153586, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:2, tx=org.jboss.cache.transaction.DummyTransaction@10153586)]
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as org.jboss.cache.transaction.DummyTransaction@9aee72 and gtx as GlobalTransaction:<null>:2
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.TxInterceptor] calling aftercompletion for GlobalTransaction:<null>:2
                                    
                                    2008-01-25 11:38:16,773 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.TxInterceptor] running commit for GlobalTransaction:<null>:2
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.NotificationInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:2)
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:2)
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] Commit called with no modifications; ignoring.
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:2)
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] Not registered for any handlers, passing up the chain.
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.OptimisticLockingInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:2)
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:2)
                                    
                                    2008-01-25 11:38:16,773 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:2
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Merging data since node is dirty
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Versioning is implicit; incrementing.
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Setting version of node /quotes/2 from Ver=0 to Ver=1
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.OptimisticCreateIfNotExistsInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:2)
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.OptimisticCreateIfNotExistsInterceptor] Not registered for any handlers, passing up the chain.
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:2)
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Not registered for any handlers, passing up the chain.
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.OptimisticNodeInterceptor] read Method MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:2) called - Not handling, passing on.
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.CallInterceptor] Suppressing invocation of method MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:2) on cache.
                                    
                                    2008-01-25 11:38:16,773 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:2
                                    
                                    2008-01-25 11:38:16,773 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as null and gtx as null
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
                                    
                                    2008-01-25 11:38:16,773 INFO [STDOUT] 2008-01-25 11:38:16,773 DEBUG [at.sit.cdms.web.actions.test.AddItem] - Added item with index of 2
                                    
                                    2008-01-25 11:38:16,773 DEBUG [at.sit.cdms.web.actions.test.AddItem] Added item with index of 2
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.web.tomcat.security.SecurityAssociationValve] End invoke, callernull
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:null
                                    
                                    2008-01-25 11:38:16,773 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:null
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] filter name=org.jboss.security.plugins.JBossSecurityContext, exclude=false
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] findClass(org.jboss.security.plugins.JBossSecurityContext) called
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@1a4f8a6{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/cmds.ear/ ,addedOrder=16} name=org.jboss.security.plugins.JBossSecurityContext, loadClassDepth=0
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] Loaded class from cache, org.jboss.security.plugins.JBossSecurityContext@2f3fe0<CodeSource: (vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/lib/jbosssx.jar <no signer certificates>)>
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@1a4f8a6{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/cmds.ear/ ,addedOrder=16} name=org.jboss.security.plugins.JBossSecurityContext class=class org.jboss.security.plugins.JBossSecurityContext cl=org.jboss.mx.loading.UnifiedClassLoader3@14c7cd{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/conf/jboss-service.xml ,addedOrder=2}
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] filter name=org.jboss.security.plugins.JBossSecurityContextUtil, exclude=false
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] findClass(org.jboss.security.plugins.JBossSecurityContextUtil) called
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@1a4f8a6{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/cmds.ear/ ,addedOrder=16} name=org.jboss.security.plugins.JBossSecurityContextUtil, loadClassDepth=0
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] Loaded class from cache, org.jboss.security.plugins.JBossSecurityContextUtil@1793657<CodeSource: (vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/lib/jbosssx.jar <no signer certificates>)>
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@1a4f8a6{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/cmds.ear/ ,addedOrder=16} name=org.jboss.security.plugins.JBossSecurityContextUtil class=class org.jboss.security.plugins.JBossSecurityContextUtil cl=org.jboss.mx.loading.UnifiedClassLoader3@14c7cd{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/conf/jboss-service.xml ,addedOrder=2}
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:null
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.web.tomcat.security.SecurityAssociationValve] Begin invoke, callernull
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                    
                                    2008-01-25 11:38:17,476 INFO [STDOUT] 2008-01-25 11:38:17,476 DEBUG [at.sit.cdms.web.actions.ActionFactory] - Looking for bean addItem
                                    
                                    2008-01-25 11:38:17,476 DEBUG [at.sit.cdms.web.actions.ActionFactory] Looking for bean addItem
                                    
                                    2008-01-25 11:38:17,476 DEBUG [org.springframework.beans.factory.support.DefaultListableBeanFactory] Returning cached instance of singleton bean 'addItem'
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Invoked on cache instance [null] and InvocationContext [InvocationContext{methodCall=MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = null ...)transaction=null, globalTransaction=null, optionOverrides=Option{failSilently=false, cacheModeLocal=true, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false}, originLocal=true, txHasMods=false}]
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting up transactional context.
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Setting tx as null and gtx as null
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.CacheMgmtInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = null ...)
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.TxInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = null ...)
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.TxInterceptor] Creating transaction for thread Thread[http-127.0.0.1-8080-2,5,jboss]
                                    
                                    2008-01-25 11:38:17,476 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-127.0.0.1-8080-2,5,jboss]
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is null
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.CacheImpl.CMDS-Cluster] created new GTX: GlobalTransaction:<null>:3, local TX=org.jboss.cache.transaction.DummyTransaction@128493c
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.TxInterceptor] Registering sync handler for tx org.jboss.cache.transaction.DummyTransaction@128493c, gtx GlobalTransaction:<null>:3
                                    
                                    2008-01-25 11:38:17,476 DEBUG [org.jboss.cache.transaction.DummyTransaction] registering synchronization handler tx=org.jboss.cache.transaction.DummyTransaction@19417404, handlers=[]
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.TxInterceptor] registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:3, tx=org.jboss.cache.transaction.DummyTransaction@19417404))
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.NotificationInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:3 ...)
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.NotificationInterceptor] Not registered for any handlers, passing up the chain.
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:3 ...)
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:3 ...)
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] must load, node null
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] load element /quotes/3 mustLoad=true
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] createTempNode n org.jboss.cache.invocation.NodeInvocationDelegate@441260
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] loadNode /quotes/3
                                    
                                    2008-01-25 11:38:17,476 DEBUG [org.jboss.cache.loader.JDBCCacheLoader] executing sql: select node from jbosscache where fqn=? (/quotes/3)
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying ManagedConnection from pool: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@aa045f[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113 handles=0 lastUse=1201257496757 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@16c73b1 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@11f80c3 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@13e9853 txSync=null]
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@aa045f[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113 handles=0 lastUse=1201257496757 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@16c73b1 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@11f80c3 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@13e9853 txSync=null] [InUse/Available/Max]: [1/9/10]
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] No transaction, no need to enlist: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@aa045f[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113 handles=0 lastUse=1201257496757 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@16c73b1 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@11f80c3 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@13e9853 txSync=null]
                                    
                                    2008-01-25 11:38:17,476 TRACE [org.jboss.cache.loader.ManagedConnectionFactory] Connection checked out: org.jboss.resource.adapter.jdbc.jdk5.WrappedConnectionJDK5@1129113
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] connectionClosed called mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] unregisterConnection: 0 handles left
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] isManagedConnectionFree=true mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] delisting org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@aa045f[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113 handles=0 lastUse=1201257496757 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@16c73b1 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@11f80c3 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@13e9853 txSync=null]
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@aa045f[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113 handles=0 lastUse=1201257496757 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@16c73b1 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@11f80c3 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@13e9853 txSync=null]
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@aa045f[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@182d113 handles=0 lastUse=1201257497523 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$OnePool@16c73b1 context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@11f80c3 xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@13e9853 txSync=null] [InUse/Available/Max]: [0/10/10]
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] nodeExists false
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] Setting dataLoaded to true
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticLockingInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:3 ...)
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticLockingInterceptor] Not registered for any handlers, passing up the chain.
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:3 ...)
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Not registered for any handlers, passing up the chain.
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticCreateIfNotExistsInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:3 ...)
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Invoked with method call MethodName: _put; MethodIdInteger: 3; Args: ( arg[0] = GlobalTransaction:<null>:3 ...)
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticNodeInterceptor] Setting versioning for node /quotes/3 to implicit
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.RegionManager] Contents of RegionsRegistry: {/=RegionImpl{fqn=/; classloader=null; status=ACTIVE; eviction=true; timerThreadRegistered=true}, /quotes=RegionImpl{fqn=/quotes; classloader=null; status=ACTIVE; eviction=true; timerThreadRegistered=true}}
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.RegionManager] Trying next region /quotes and got RegionImpl{fqn=/quotes; classloader=null; status=ACTIVE; eviction=true; timerThreadRegistered=true}
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.RegionManager] Contents of RegionsRegistry: {/=RegionImpl{fqn=/; classloader=null; status=ACTIVE; eviction=true; timerThreadRegistered=true}, /quotes=RegionImpl{fqn=/quotes; classloader=null; status=ACTIVE; eviction=true; timerThreadRegistered=true}}
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.RegionManager] Trying next region /quotes and got RegionImpl{fqn=/quotes; classloader=null; status=ACTIVE; eviction=true; timerThreadRegistered=true}
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Adding event EvictedEN[fqn=/quotes/3 event=ADD_ELEMENT_EVENT diff=1] to region at /quotes
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished updating node
                                    
                                    2008-01-25 11:38:17,523 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing beforeCompletion for tx=org.jboss.cache.transaction.DummyTransaction@19417404, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:3, tx=org.jboss.cache.transaction.DummyTransaction@19417404)]
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.TxInterceptor] Running beforeCompletion on gtx GlobalTransaction:<null>:3
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as org.jboss.cache.transaction.DummyTransaction@128493c and gtx as GlobalTransaction:<null>:3
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.TxInterceptor] No modifications in this tx. Skipping beforeCompletion()
                                    
                                    2008-01-25 11:38:17,523 DEBUG [org.jboss.cache.transaction.DummyTransaction] processing afterCompletion for tx=org.jboss.cache.transaction.DummyTransaction@19417404, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:3, tx=org.jboss.cache.transaction.DummyTransaction@19417404)]
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as org.jboss.cache.transaction.DummyTransaction@128493c and gtx as GlobalTransaction:<null>:3
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.TxInterceptor] calling aftercompletion for GlobalTransaction:<null>:3
                                    
                                    2008-01-25 11:38:17,523 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Running commit phase. One phase? false
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.TxInterceptor] running commit for GlobalTransaction:<null>:3
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.NotificationInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:3)
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:3)
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] transactional so don't put stuff in the cloader yet.
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.CacheStoreInterceptor] Commit called with no modifications; ignoring.
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:3)
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.CacheLoaderInterceptor] Not registered for any handlers, passing up the chain.
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticLockingInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:3)
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:3)
                                    
                                    2008-01-25 11:38:17,523 DEBUG [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Commiting successfully validated changes for GlobalTransaction GlobalTransaction:<null>:3
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Merging data since node is dirty
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Versioning is implicit; incrementing.
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticValidatorInterceptor] Setting version of node /quotes/3 from Ver=0 to Ver=1
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticCreateIfNotExistsInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:3)
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticCreateIfNotExistsInterceptor] Not registered for any handlers, passing up the chain.
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Invoked with method call MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:3)
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Not registered for any handlers, passing up the chain.
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.OptimisticNodeInterceptor] read Method MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:3) called - Not handling, passing on.
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.CallInterceptor] Suppressing invocation of method MethodName: commit; MethodIdInteger: 11; Args: ( arg[0] = GlobalTransaction:<null>:3) on cache.
                                    
                                    2008-01-25 11:38:17,523 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished local commit/rollback method for GlobalTransaction:<null>:3
                                    
                                    2008-01-25 11:38:17,523 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Finished commit phase
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting up transactional context.
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.TxInterceptor] Setting tx as null and gtx as null
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] Resetting invocation-scope options
                                    
                                    2008-01-25 11:38:17,523 INFO [STDOUT] 2008-01-25 11:38:17,523 DEBUG [at.sit.cdms.web.actions.test.AddItem] - Added item with index of 3
                                    
                                    2008-01-25 11:38:17,523 DEBUG [at.sit.cdms.web.actions.test.AddItem] Added item with index of 3
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.web.tomcat.security.RunAsListener] dataService, runAs: null
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.web.tomcat.security.SecurityAssociationValve] End invoke, callernull
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:null
                                    
                                    2008-01-25 11:38:17,523 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:null
                                    
                                    2008-01-25 11:38:19,554 TRACE [org.jboss.system.server.profileservice.hotdeploy.HDScanner] Begin deployment scan
                                    
                                    2008-01-25 11:38:19,554 TRACE [org.jboss.system.server.profile.basic.ProfileImpl] Checking applications for modifications
                                    
                                    2008-01-25 11:38:19,570 TRACE [org.jboss.system.server.profileservice.hotdeploy.HDScanner] End deployment scan
                                    
                                    2008-01-25 11:38:24,570 TRACE [org.jboss.system.server.profileservice.hotdeploy.HDScanner] Begin deployment scan
                                    
                                    2008-01-25 11:38:24,570 TRACE [org.jboss.system.server.profile.basic.ProfileImpl] Checking applications for modifications
                                    
                                    2008-01-25 11:38:24,585 TRACE [org.jboss.system.server.profileservice.hotdeploy.HDScanner] End deployment scan
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] filter name=org.jboss.security.plugins.JBossSecurityContext, exclude=false
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] findClass(org.jboss.security.plugins.JBossSecurityContext) called
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=org.jboss.security.plugins.JBossSecurityContext, loadClassDepth=0
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.mx.loading.RepositoryClassLoader] Loaded class from cache, org.jboss.security.plugins.JBossSecurityContext@2f3fe0<CodeSource: (vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/lib/jbosssx.jar <no signer certificates>)>
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=org.jboss.security.plugins.JBossSecurityContext class=class org.jboss.security.plugins.JBossSecurityContext cl=org.jboss.mx.loading.UnifiedClassLoader3@14c7cd{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/conf/jboss-service.xml ,addedOrder=2}
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] filter name=org.jboss.security.plugins.JBossSecurityContextUtil, exclude=false
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] findClass(org.jboss.security.plugins.JBossSecurityContextUtil) called
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=org.jboss.security.plugins.JBossSecurityContextUtil, loadClassDepth=0
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.mx.loading.RepositoryClassLoader] Loaded class from cache, org.jboss.security.plugins.JBossSecurityContextUtil@1793657<CodeSource: (vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/lib/jbosssx.jar <no signer certificates>)>
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=org.jboss.security.plugins.JBossSecurityContextUtil class=class org.jboss.security.plugins.JBossSecurityContextUtil cl=org.jboss.mx.loading.UnifiedClassLoader3@14c7cd{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/conf/jboss-service.xml ,addedOrder=2}
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:{}
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.web.tomcat.security.JaccContextValve] MetaData:org.jboss.metadata.web.jboss.JBossWebMetaData@1f:principalToRoleSetMap{}
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.web.tomcat.security.SecurityAssociationValve] Begin invoke, callernull
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.web.tomcat.security.RunAsListener] HtmlAdaptor, runAs: null
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.web.tomcat.security.RunAsListener] HtmlAdaptor, runAs: null
                                    
                                    2008-01-25 11:38:28,976 TRACE [org.jboss.jmx.adaptor.html.HtmlAdaptorServlet] invokeOp, name=jboss.cache:service=CMDSPersistentCache
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.web.tomcat.security.RunAsListener] jsp, runAs: null
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.web.tomcat.security.RunAsListener] jsp, runAs: null
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] filter name=java.lang.StringEditor, exclude=false
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] findClass(java.lang.StringEditor) called
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=java.lang.StringEditor, loadClassDepth=0
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.UnifiedClassLoader] loadClassImpl, name=java.lang.StringEditor, resolve=false
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.RepositoryClassLoader] attempt(1) was: true for :org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29}
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.LoadMgr3] registerLoaderThread, ucl=org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29}, t=Thread[http-127.0.0.1-8080-1,5,jboss], prevT=null
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.LoadMgr3] Begin beginLoadTask, task=org.jboss.mx.loading.ClassLoadingTask@5062a5{classname: java.lang.StringEditor, requestingThread: Thread[http-127.0.0.1-8080-1,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29}, loadedClass: nullnull, loadOrder: 2147483647, loadException: null, threadTaskCount: 0, state: 0, #CCE: 0}
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClassLocally, org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=java.lang.StringEditor
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClassLocally, org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=java.lang.StringEditor not found
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.LoadMgr3] End beginLoadTask, ClassNotFoundException
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.LoadMgr3] Begin endLoadTask, task=org.jboss.mx.loading.ClassLoadingTask@5062a5{classname: java.lang.StringEditor, requestingThread: Thread[http-127.0.0.1-8080-1,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29}, loadedClass: nullnull, loadOrder: 2147483647, loadException: null, threadTaskCount: 0, state: 0, #CCE: 0}
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.RepositoryClassLoader] release(1) for :org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29}
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.RepositoryClassLoader] released, holds: 0
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=java.lang.StringEditor not found
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] filter name=org.jboss.util.propertyeditor.StringEditor, exclude=false
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] findClass(org.jboss.util.propertyeditor.StringEditor) called
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=org.jboss.util.propertyeditor.StringEditor, loadClassDepth=0
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.RepositoryClassLoader] Loaded class from cache, org.jboss.util.propertyeditor.StringEditor@def14f<CodeSource: (file:/C:/jboss/jboss-5.0.0.Beta3/lib/jboss-common-core.jar <no signer certificates>)>
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=org.jboss.util.propertyeditor.StringEditor class=class org.jboss.util.propertyeditor.StringEditor cl=org.jboss.system.NoAnnotationURLClassLoader@c7b00c
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.web.tomcat.security.RunAsListener] jsp, runAs: null
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.web.tomcat.security.RunAsListener] jsp, runAs: null
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.web.tomcat.security.RunAsListener] HtmlAdaptor, runAs: null
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.web.tomcat.security.RunAsListener] HtmlAdaptor, runAs: null
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.web.tomcat.security.SecurityAssociationValve] End invoke, callernull
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:null
                                    
                                    2008-01-25 11:38:28,991 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:null
                                    
                                    2008-01-25 11:38:29,585 TRACE [org.jboss.system.server.profileservice.hotdeploy.HDScanner] Begin deployment scan
                                    
                                    2008-01-25 11:38:29,585 TRACE [org.jboss.system.server.profile.basic.ProfileImpl] Checking applications for modifications
                                    
                                    2008-01-25 11:38:29,601 TRACE [org.jboss.system.server.profileservice.hotdeploy.HDScanner] End deployment scan
                                    
                                    2008-01-25 11:38:33,038 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] subject: null
                                    
                                    2008-01-25 11:38:33,038 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] getManagedConnection trackByTx=true tx=null
                                    
                                    2008-01-25 11:38:33,038 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying ManagedConnection from pool: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@15a6eb9[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1b4cff handles=0 lastUse=1201257487523 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@13d346d context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1a2327a xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@5c0deb txSync=null]
                                    
                                    2008-01-25 11:38:33,038 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Got connection from pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@15a6eb9[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1b4cff handles=0 lastUse=1201257487523 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@13d346d context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1a2327a xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@5c0deb txSync=null] [InUse/Available/Max]: [1/19/20]
                                    
                                    2008-01-25 11:38:33,038 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] No transaction, no need to enlist: org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@15a6eb9[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1b4cff handles=0 lastUse=1201257487523 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@13d346d context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1a2327a xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@5c0deb txSync=null]
                                    
                                    2008-01-25 11:38:33,038 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] connectionClosed called mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1b4cff
                                    
                                    2008-01-25 11:38:33,038 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] unregisterConnection: 0 handles left
                                    
                                    2008-01-25 11:38:33,038 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] isManagedConnectionFree=true mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1b4cff
                                    
                                    2008-01-25 11:38:33,038 TRACE [org.jboss.resource.connectionmanager.TxConnectionManager] delisting org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@15a6eb9[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1b4cff handles=0 lastUse=1201257487523 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@13d346d context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1a2327a xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@5c0deb txSync=null]
                                    
                                    2008-01-25 11:38:33,038 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool kill=false cl=org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@15a6eb9[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1b4cff handles=0 lastUse=1201257487523 permit=true trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@13d346d context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1a2327a xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@5c0deb txSync=null]
                                    
                                    2008-01-25 11:38:33,038 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener@15a6eb9[state=NORMAL mc=org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1b4cff handles=0 lastUse=1201257513038 permit=false trackByTx=false mcp=org.jboss.resource.connectionmanager.JBossManagedConnectionPool$PoolBySubject@13d346d context=org.jboss.resource.connectionmanager.InternalManagedConnectionPool@1a2327a xaResource=org.jboss.resource.connectionmanager.TxConnectionManager$LocalXAResource@5c0deb txSync=null] [InUse/Available/Max]: [0/20/20]
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] filter name=org.jboss.security.plugins.JBossSecurityContext, exclude=false
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] findClass(org.jboss.security.plugins.JBossSecurityContext) called
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=org.jboss.security.plugins.JBossSecurityContext, loadClassDepth=0
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] Loaded class from cache, org.jboss.security.plugins.JBossSecurityContext@2f3fe0<CodeSource: (vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/lib/jbosssx.jar <no signer certificates>)>
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=org.jboss.security.plugins.JBossSecurityContext class=class org.jboss.security.plugins.JBossSecurityContext cl=org.jboss.mx.loading.UnifiedClassLoader3@14c7cd{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/conf/jboss-service.xml ,addedOrder=2}
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] filter name=org.jboss.security.plugins.JBossSecurityContextUtil, exclude=false
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] findClass(org.jboss.security.plugins.JBossSecurityContextUtil) called
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=org.jboss.security.plugins.JBossSecurityContextUtil, loadClassDepth=0
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] Loaded class from cache, org.jboss.security.plugins.JBossSecurityContextUtil@1793657<CodeSource: (vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/lib/jbosssx.jar <no signer certificates>)>
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=org.jboss.security.plugins.JBossSecurityContextUtil class=class org.jboss.security.plugins.JBossSecurityContextUtil cl=org.jboss.mx.loading.UnifiedClassLoader3@14c7cd{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/conf/jboss-service.xml ,addedOrder=2}
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.security.SecurityRolesAssociation] Setting threadlocal:{}
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.web.tomcat.security.JaccContextValve] MetaData:org.jboss.metadata.web.jboss.JBossWebMetaData@1f:principalToRoleSetMap{}
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.web.tomcat.security.SecurityAssociationValve] Begin invoke, callernull
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.web.tomcat.security.RunAsListener] HtmlAdaptor, runAs: null
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.web.tomcat.security.RunAsListener] HtmlAdaptor, runAs: null
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.jmx.adaptor.html.HtmlAdaptorServlet] invokeOp, name=jboss.cache:service=CMDSPersistentCache
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.web.tomcat.security.RunAsListener] jsp, runAs: null
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.web.tomcat.security.RunAsListener] jsp, runAs: null
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] filter name=java.lang.StringEditor, exclude=false
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.web.tomcat.service.WebAppClassLoader] findClass(java.lang.StringEditor) called
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] loadClass org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29} name=java.lang.StringEditor, loadClassDepth=0
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.mx.loading.UnifiedClassLoader] loadClassImpl, name=java.lang.StringEditor, resolve=false
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.mx.loading.RepositoryClassLoader] attempt(1) was: true for :org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29}
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.mx.loading.LoadMgr3] registerLoaderThread, ucl=org.jboss.mx.loading.UnifiedClassLoader3@b77928{ url=vfsfile:/C:/jboss/jboss-5.0.0.Beta3/server/default/deploy/jmx-console.war/ ,addedOrder=29}, t=Thread[http-127.0.0.1-8080-2,5,jboss], prevT=null
                                    
                                    2008-01-25 11:38:33,476 TRACE [org.jboss.mx.loading.LoadMgr3] Begin beginLoadTask, task=org.jboss.mx.loading.ClassLoadingTask@1d9726f{classname: java.lang.StringEditor, requestingThread: Thread[http-127.0.0.1-8080-2,5,jboss], request


                                    1 2 Previous Next