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 View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4122633#4122633 Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4122633 _______________________________________________ jboss-user mailing list [email protected] https://lists.jboss.org/mailman/listinfo/jboss-user
