4 Replies Latest reply on Jan 22, 2009 1:28 AM by Ramon Wang

    Error function when working with passivation.

    Ramon Wang Newbie

      Hi guys, I wrote a test application to test passivation function with JDBCCacheLoader, the application is simple, two threads, the writer thread try to put 20 nodes into the cache and the reader thread do the read operation periodically. I only set maxNodes to be 10 and passivation to be true, so I was except that there should be only 10 nodes in the cache and the other 10 are in the database, I ran the test, before passivation every thing is correct, but after the passivation operation the reader threads can not read nothing, i checked the database found JBOSSCACHE.NODE column seems contain an empty object for the object passivated here, i did try to debug the cache, found when jbossCache try to passivate a node, the node data property is always NULL, i'm not sure what the problem it was, so can anybody help me? Thanks.

      My cache configuration:

      <?xml version="1.0" encoding="UTF-8"?>
      <jbosscache xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns="urn:jboss:jbosscache-core:config:3.0">
      
       <!-- Configure the TransactionManager -->
       <transaction transactionManagerLookupClass="org.jboss.cache.transaction.GenericTransactionManagerLookup"/>
      
       <!-- Specific eviction policy configurations -->
       <eviction wakeUpInterval="5000">
       <!-- Cache wide default -->
       <default algorithmClass="org.jboss.cache.eviction.LRUAlgorithm" eventQueueSize="200000">
       <property name="maxNodes" value="5000" />
       <property name="timeToLive" value="3000" />
       </default>
       <region name="/testRegion">
       <property name="maxNodes" value="10" />
       <property name="timeToLive" value="3000" />
       </region>
       </eviction>
      
       <!-- Cache Passivation for Tree Cache
       On passivation, The objects are written to the backend store on eviction if passivation
       is true, otherwise the objects are persisted. On activation, the objects are restored in
       the memory cache and removed from the cache loader if 'passivation' attribute is true,
       otherwise the objects are only loaded from the cache loader -->
       <loaders passivation="true" shared="false">
       <!-- if passivation is true, only the first cache loader is used; the rest are ignored -->
       <loader
       class="org.jboss.cache.loader.JDBCCacheLoader"
       async="false"
       fetchPersistentState="true"
       ignoreModifications="false"
       purgeOnStartup="false">
       <properties>
       cache.jdbc.table.name=jbosscache
       cache.jdbc.table.create=true
       cache.jdbc.table.drop=true
       cache.jdbc.table.primarykey=jbosscache_pk
       cache.jdbc.fqn.column=fqn
       cache.jdbc.fqn.type=varchar(255)
       cache.jdbc.node.column=node
       cache.jdbc.node.type=blob
       cache.jdbc.parent.column=parent
       cache.jdbc.sql-concat=1 || 2
       cache.jdbc.driver =oracle.jdbc.driver.OracleDriver
       cache.jdbc.url=jdbc:oracle:thin:@15.154.146.115:1521:perf
       cache.jdbc.user=malibu_ramon
       cache.jdbc.password=malibu_ramon
       </properties>
       </loader>
       </loaders>
      </jbosscache>
      


        • 1. Re: Error function when working with passivation.
          Ramon Wang Newbie

          BTW, i was using JDK1.6 and following is some log output:

          2008-12-26 13:28:16,415 [Thread-1] DEBUG (AdjListJDBCCacheLoader.java:147) - executing sql: select fqn from jbosscache where parent=? (/testRegion)
          2008-12-26 13:28:16,509 [Thread-1] INFO (ReadThread.java:40) - currently node (/testRegion) has 20 subnodes
          2008-12-26 13:28:16,509 [Thread-1] INFO (ReadThread.java:44) - Get value 'Name is Ramon 15, age is 20.' in node '/testRegion/15'.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,025 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,056 [EvictionTimer-0] DEBUG (BaseEvictionAlgorithm.java:438) - Visiting node that was not added to eviction queues. Assuming that it has 1 element.
          2008-12-26 13:28:20,134 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:20,290 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:20,447 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:20,603 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:20,806 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:20,978 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:21,134 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:21,290 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:21,447 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:21,634 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:21,790 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:21,962 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:22,118 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:22,290 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:22,478 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:22,634 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:22,806 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:22,978 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:23,134 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:23,290 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:23,462 [EvictionTimer-0] DEBUG (AdjListJDBCCacheLoader.java:580) - executing sql: update jbosscache set node=? where fqn=?
          2008-12-26 13:28:26,525 [Thread-1] DEBUG (AdjListJDBCCacheLoader.java:147) - executing sql: select fqn from jbosscache where parent=? (/testRegion)
          2008-12-26 13:28:26,618 [Thread-1] INFO (ReadThread.java:40) - currently node (/testRegion) has 20 subnodes
          2008-12-26 13:28:26,618 [Thread-1] DEBUG (AdjListJDBCCacheLoader.java:431) - executing sql: select node from jbosscache where fqn=? (/testRegion/19)
          2008-12-26 13:28:26,790 [Thread-1] DEBUG (AdjListJDBCCacheLoader.java:147) - executing sql: select fqn from jbosscache where parent=? (/testRegion/19)
          2008-12-26 13:28:26,868 [Thread-1] DEBUG (ActivationInterceptor.java:215) - no children UnversionedNode[ /testRegion/19]
          2008-12-26 13:28:26,947 [Thread-1] INFO (ReadThread.java:44) - Get value 'null' in node '/testRegion/19'.


          Pay attention to the RED color, you can see from the log that before passivation everything work well, but after passivation, when the read thread try to activation, the reader got nothing.

          And also there is some following statements, I don't know what that mean...Is there a relationship?
          Visiting node tha
          t was not added to eviction queues. Assuming that it has 1 element.


          • 2. Re: Error function when working with passivation.
            Ramon Wang Newbie

            It seems no body care about my problem :(

            Anyway, I'm still doing the test and finally find that whenever I write the following code in my run() method of the reader Thread, the reader has a big chance to get null from a specific node which should have value, the code is:

            @Override
             public void run() {
             while(true) {
             try {
             Thread.sleep(1000);
             } catch (InterruptedException e) {
             // TODO Auto-generated catch block
             e.printStackTrace();
             }
             int max = w.getKey();
             Node<String, TestBean> regionNode = cache.getNode(Fqn.fromString(region)); // just a test to check the root node of my test
             max = regionNode.getChildren().size();
             logger.info("currently node (/testRegion) has " + max + " subnodes");
             int readPoint = Math.abs(RANDOM.nextInt() % (max == 0 ? 1 : max));
             if (readPoint == 0) {
             readPoint = 1;
             }
             testRegion = Fqn.fromString(region + "/" + readPoint);
             TestBean value = cache.get(testRegion, "DATA");
             logger.info("Get value ++++++++++++++ '" + value + "' in node '" + testRegion.toString() + "'.");
             logger.info("/n/n/n");
             }
             }


            Please pay attention to the red color, it seems has a significant impact to the passivation Thread, when it was uncommented, my reader thread will get nothing. When this part of code (the red part) was removed, everything is OK.

            Can anybody give me some clues about it, any response will be appreciated.

            • 3. Re: Error function when working with passivation.
              Manik Surtani Master

              This line in your config:

               cache.jdbc.sql-concat=1 || 2
              


              may be the issue. AFAIR that was a hack for Derby's non-standard SQL string concatenation. Try removing that line altogether, or replacing it with

               cache.jdbc.sql-concat=concat(1,2)
              


              See the comments in cache-jdbc.properties which is in the JBC testsuite for details.





              • 4. Re: Error function when working with passivation.
                Ramon Wang Newbie

                OK, thanks Manik, I will try it later.