3 Replies Latest reply on Sep 7, 2006 3:13 AM by lior.dra

    Performence

    lior.dra
    lior.dra Sep 6, 2006 11:10 AM

      Hi
      I have been trying to use JbossCache 1.4 SP1, as a caching solution,
      However I encounter performence issues,
      I have not been able to write more then 1000 updates per sec, on a single node, and I need a solution able to write as many as 15,000 per sec.
      I have been written a small test to demonstrate:
      I have been using MR. Ben Wang's Address and Student classes, along with
      ../etc/META-INF/replSync-service.xml
      I have compiled the classes with the aopc compiler.
      the jboss-aop.xml file I am using is the one under the .../examples/PojoCache/ ....... .

      Test setup 2 nodes:

      Machine 1:
      JVM 1.5.07
      Fedora 5 linux.
      1GM memory

      Machine 2
      JVM 1.5.07
      Solaris 10 2GM memory

      Use Case 1:
      When I run this code unclustered I can update 12,000 times per second

      Use Case 2:
      When I run this code in a 2 node cluster the performence drops to something like 900 - 1200 updates per second.

      Use Case 3:
      When I run this code with the 's' param, one one node, meaning I have just one writer node, I get the same results: 900 - 1200 updates per second.

      I have noticed that the CPU usage rises to 80 - 100 % even when the node is not writing / reading the cache.


      What am I doing wring ?
      is this the kind of performence I can expect?
      According to the following link
      http://wiki.jboss.org/wiki/Wiki.jsp?page=WhatShouldWeExpectOfThePojoCachePerformance I should be just fine, but the results I am getting is very far from it, whay is that ?

      Thanks
      Lior


      my class is:

      package com.protagonis.cache;

      //import org.jboss.cache.Fqn;
      //import org.jboss.cache.PropertyConfigurator;
      //mport org.jboss.cache.aop.PojoCache;

      import java.util.*;

      import javax.naming.*;
      import javax.transaction.*;

      import org.jboss.cache.*;
      import org.jboss.cache.aop.*;

      import com.protagonis.test.utils.*;

      public class ManualTestCacheJbossExample {
      private static final String base_dir = "./etc/resources/configuration/";

      private PojoCache tree;

      public static void main(String[] argv) throws Exception {
      ManualTestCacheJbossExample ct = new ManualTestCacheJbossExample();


      ct.tree = ct.StartCache();

      if (argv.length > 1)
      if (argv[1].equals("s")) {
      while (true) {
      Thread.sleep(0, 10);
      }
      }

      /*
      * Timing.assertElapseTime(ct, "doAspect", new Object[] { new Integer(
      * argv[0]).intValue(), }, 100000L);
      */

      ct.doAspect(new Integer(argv[0]).intValue());
      ct.tree.stop();

      }

      public ManualTestCacheJbossExample() {
      }

      public void doAspect(int howMany) {

      try {
      Student st1 = new Student();
      st1.setSchool("school1");
      st1.setName("Name1");
      Address adr = new Address();
      adr.setCity("city");
      adr.setStreet("str");
      adr.setZip(1);
      st1.setAddress(adr);
      Fqn fqn = Fqn.fromString("a/b");

      int count = 1;

      while (count < howMany) {

      try {
      Student std2 = (Student) tree.getObject(fqn);

      if (std2 == null) {
      tree.putObject(fqn, st1);
      continue;
      }

      Address adr2 = std2.getAddress();
      adr.setZip(adr.getZip() + 1);

      if (count % 1000 == 0)
      System.out
      .println(" Count " + count + " Zip "
      + adr2.getZip() + 1 + " Name "
      + std2.getName());

      } catch (Exception e) {
      e.printStackTrace();
      }
      count++;

      }
      } catch (Exception e) {

      e.printStackTrace();
      }

      }

      public PojoCache StartCache() {

      try {
      InitJvm.init();
      tree = new PojoCache();

      PropertyConfigurator config = new PropertyConfigurator(); // configure

      config.configure(tree, base_dir + "replSync-service.xml");
      tree.setClusterName("Sample-Cluster");
      tree.start(); // kick start the cache

      Thread.sleep(5000);
      return tree;
      } catch (Exception e) {
      e.printStackTrace();
      }
      return null;
      }

      }








      • 2365 Views
      • Tags:
        • 1. Re: Performence
          ben.wang Sep 6, 2006 7:11 PM (in response to lior.dra)

          Two options.

          1) You can run the examples that I posted on the Wiki. It can be found from the cvs under Branch_JBossCache_1_4_0, tests/scripts/readme.txt.

          2) Use your own example and do inspect the log file (under DEBUG). If you only do field update, you should see only _put() but no putObject(). Does that make sense?

            • Actions
          • 2. Re: Performence
            ben.wang Sep 6, 2006 7:12 PM (in response to lior.dra)

            Oh, if you want, you can also send me your driver program. I think your example looks fine. But this is not the whole thing, is it?

              • Actions
            • 3. Re: Performence
              lior.dra
              lior.dra Sep 7, 2006 3:13 AM (in response to lior.dra)

              Hey,


              "Use your own example and do inspect the log file (under DEBUG). If you only do field update, you should see only _put() but no putObject(). Does that make sense?"

              The is the DEBUG log print out, for the code in my prev message:

              07/09 09:43:37,607 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b", AOPInstance, "false")
              07/09 09:43:37,611 [main] DEBUG org.jboss.cache.marshall.RegionManager - getRegion(): user-specified region not found: /a/b
              07/09 09:43:37,611 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b", __jboss:internal:class__, "false")
              07/09 09:43:37,611 [main] DEBUG org.jboss.cache.TreeCache - putObject(): Fqn:/a/b
              07/09 09:43:37,614 [main] DEBUG org.jboss.cache.TreeCache - created new GTX: GlobalTransaction:<192.168.11.105:33069>:1, local TX=org.jboss.cache.transaction.DummyTransaction@1d85f79
              07/09 09:43:37,614 [main] DEBUG org.jboss.cache.TreeCache - lockPojo(): Fqn:/a/b Owner: GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:37,615 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b, _lock_, LOCK, true)]
              07/09 09:43:37,615 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - local transaction exists - registering global tx if not present for Thread[main,5,main]
              07/09 09:43:37,615 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Associated gtx in txTable is GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:37,615 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Registering sync handler for tx org.jboss.cache.transaction.DummyTransaction@1d85f79, gtx GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:37,617 [main] DEBUG org.jboss.cache.transaction.DummyTransaction - registering synchronization handler tx=org.jboss.cache.transaction.DummyTransaction@1d85f79, handlers=[]
              07/09 09:43:37,617 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<192.168.11.105:33069>:1, tx=org.jboss.cache.transaction.DummyTransaction@1d85f79))
              07/09 09:43:37,617 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b, _lock_, LOCK, true)
              07/09 09:43:37,618 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /a/b for owner GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:37,618 [main] DEBUG org.jboss.cache.Node - created child: fqn=/a
              07/09 09:43:37,618 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a, caller=GlobalTransaction:<192.168.11.105:33069>:1, lock=
              07/09 09:43:37,619 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a, caller=GlobalTransaction:<192.168.11.105:33069>:1, lock=read owners=[GlobalTransaction:<192.168.11.105:33069>:1]
              07/09 09:43:37,619 [main] DEBUG org.jboss.cache.Node - created child: fqn=/a/b
              07/09 09:43:37,619 [main] DEBUG org.jboss.cache.Node - acquiring WL: fqn=/a/b, caller=GlobalTransaction:<192.168.11.105:33069>:1, lock=
              07/09 09:43:37,619 [main] DEBUG org.jboss.cache.Node - acquired WL: fqn=/a/b, caller=GlobalTransaction:<192.168.11.105:33069>:1, lock=write owner=GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:37,619 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b, _lock_, LOCK, true) on cache.
              07/09 09:43:37,619 [main] DEBUG org.jboss.cache.TreeCache - _put(GlobalTransaction:<192.168.11.105:33069>:1, "/a/b", _lock_, LOCK)
              07/09 09:43:37,621 [main] DEBUG org.jboss.cache.transaction.DummyTransaction - registering synchronization handler org.jboss.cache.aop.PojoTxSynchronizationHandler@10e3293
              07/09 09:43:37,621 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b", AOPInstance, "false")
              07/09 09:43:37,622 [main] DEBUG org.jboss.cache.aop.TreeCacheAopDelegate - putObject(): fqn: /a/b
              07/09 09:43:37,640 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b, {__jboss:internal:class__=class com.protagonis.cache.Student, AOPInstance=org.jboss.cache.aop.AOPInstance@12a3722, name=Name1, school=school1}, true)]
              07/09 09:43:37,640 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - local transaction exists - registering global tx if not present for Thread[main,5,main]
              07/09 09:43:37,640 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Associated gtx in txTable is GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:37,641 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Transaction org.jboss.cache.transaction.DummyTransaction@1d85f79 is already registered.
              07/09 09:43:37,641 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b, {__jboss:internal:class__=class com.protagonis.cache.Student, AOPInstance=org.jboss.cache.aop.AOPInstance@12a3722, name=Name1, school=school1}, true)
              07/09 09:43:37,641 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Suppressing locking
              07/09 09:43:37,641 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Creating nodes if necessary
              07/09 09:43:37,641 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b, {__jboss:internal:class__=class com.protagonis.cache.Student, AOPInstance=org.jboss.cache.aop.AOPInstance@12a3722, name=Name1, school=school1}, true) on cache.
              07/09 09:43:37,641 [main] DEBUG org.jboss.cache.TreeCache - _put(GlobalTransaction:<192.168.11.105:33069>:1, "/a/b", {__jboss:internal:class__=class com.protagonis.cache.Student, AOPInstance=org.jboss.cache.aop.AOPInstance@12a3722, name=Name1, school=school1})
              07/09 09:43:37,641 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b/address", AOPInstance, "false")
              07/09 09:43:37,641 [main] DEBUG org.jboss.cache.aop.TreeCacheAopDelegate - putObject(): fqn: /a/b/address
              07/09 09:43:37,642 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/address, {street=str, __jboss:internal:class__=class com.protagonis.cache.Address, AOPInstance=org.jboss.cache.aop.AOPInstance@89cf1e, zip=1, city=city}, true)]
              07/09 09:43:37,642 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - local transaction exists - registering global tx if not present for Thread[main,5,main]
              07/09 09:43:37,642 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Associated gtx in txTable is GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:37,642 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Transaction org.jboss.cache.transaction.DummyTransaction@1d85f79 is already registered.
              07/09 09:43:37,642 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/address, {street=str, __jboss:internal:class__=class com.protagonis.cache.Address, AOPInstance=org.jboss.cache.aop.AOPInstance@89cf1e, zip=1, city=city}, true)
              07/09 09:43:37,642 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Suppressing locking
              07/09 09:43:37,642 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Creating nodes if necessary
              07/09 09:43:37,642 [main] DEBUG org.jboss.cache.Node - created child: fqn=/a/b/address
              07/09 09:43:37,643 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/address, {street=str, __jboss:internal:class__=class com.protagonis.cache.Address, AOPInstance=org.jboss.cache.aop.AOPInstance@89cf1e, zip=1, city=city}, true) on cache.
              07/09 09:43:37,643 [main] DEBUG org.jboss.cache.TreeCache - _put(GlobalTransaction:<192.168.11.105:33069>:1, "/a/b/address", {street=str, __jboss:internal:class__=class com.protagonis.cache.Address, AOPInstance=org.jboss.cache.aop.AOPInstance@89cf1e, zip=1, city=city})
              07/09 09:43:37,643 [main] DEBUG org.jboss.cache.aop.TreeCacheAopDelegate - _regularPutObject(): inserting with fqn: /a/b/address
              07/09 09:43:37,643 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b/courses", AOPInstance, "false")
              07/09 09:43:37,643 [main] DEBUG org.jboss.cache.aop.TreeCacheAopDelegate - putObject(): fqn: /a/b/courses
              07/09 09:43:37,644 [main] DEBUG org.jboss.cache.aop.CollectionClassHandler - collectionPutObject(): aspectized obj is a Set type of size: 0
              07/09 09:43:37,644 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/courses, __jboss:internal:class__, class java.util.LinkedHashSet, true)]
              07/09 09:43:37,644 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - local transaction exists - registering global tx if not present for Thread[main,5,main]
              07/09 09:43:37,644 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Associated gtx in txTable is GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:37,644 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Transaction org.jboss.cache.transaction.DummyTransaction@1d85f79 is already registered.
              07/09 09:43:37,644 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/courses, __jboss:internal:class__, class java.util.LinkedHashSet, true)
              07/09 09:43:37,644 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Suppressing locking
              07/09 09:43:37,644 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Creating nodes if necessary
              07/09 09:43:37,644 [main] DEBUG org.jboss.cache.Node - created child: fqn=/a/b/courses
              07/09 09:43:37,644 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/courses, __jboss:internal:class__, class java.util.LinkedHashSet, true) on cache.
              07/09 09:43:37,645 [main] DEBUG org.jboss.cache.TreeCache - _put(GlobalTransaction:<192.168.11.105:33069>:1, "/a/b/courses", __jboss:internal:class__, class java.util.LinkedHashSet)
              07/09 09:43:38,024 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/courses, AOPInstance, org.jboss.cache.aop.AOPInstance@1f17e77, true)]
              07/09 09:43:38,024 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - local transaction exists - registering global tx if not present for Thread[main,5,main]
              07/09 09:43:38,024 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Associated gtx in txTable is GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:38,024 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Transaction org.jboss.cache.transaction.DummyTransaction@1d85f79 is already registered.
              07/09 09:43:38,025 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/courses, AOPInstance, org.jboss.cache.aop.AOPInstance@1f17e77, true)
              07/09 09:43:38,025 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /a/b/courses for owner GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:38,025 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a, caller=GlobalTransaction:<192.168.11.105:33069>:1, lock=read owners=[GlobalTransaction:<192.168.11.105:33069>:1]
              07/09 09:43:38,025 [main] DEBUG org.jboss.cache.lock.IdentityLock - acquireReadLock(): caller GlobalTransaction:<192.168.11.105:33069>:1 already owns lock for /a
              07/09 09:43:38,025 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a, caller=GlobalTransaction:<192.168.11.105:33069>:1, lock=read owners=[GlobalTransaction:<192.168.11.105:33069>:1]
              07/09 09:43:38,026 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b, caller=GlobalTransaction:<192.168.11.105:33069>:1, lock=write owner=GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:38,026 [main] DEBUG org.jboss.cache.lock.IdentityLock - acquireReadLock(): caller GlobalTransaction:<192.168.11.105:33069>:1 already owns lock for /a/b
              07/09 09:43:38,026 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b, caller=GlobalTransaction:<192.168.11.105:33069>:1, lock=write owner=GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:38,026 [main] DEBUG org.jboss.cache.Node - acquiring WL: fqn=/a/b/courses, caller=GlobalTransaction:<192.168.11.105:33069>:1, lock=
              07/09 09:43:38,026 [main] DEBUG org.jboss.cache.Node - acquired WL: fqn=/a/b/courses, caller=GlobalTransaction:<192.168.11.105:33069>:1, lock=write owner=GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:38,027 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/courses, AOPInstance, org.jboss.cache.aop.AOPInstance@1f17e77, true) on cache.
              07/09 09:43:38,027 [main] DEBUG org.jboss.cache.TreeCache - _put(GlobalTransaction:<192.168.11.105:33069>:1, "/a/b/courses", AOPInstance, org.jboss.cache.aop.AOPInstance@1f17e77)
              07/09 09:43:38,027 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b/courses", AOPInstance, "false")
              07/09 09:43:38,027 [main] DEBUG org.jboss.cache.aop.TreeCacheAopDelegate - _regularPutObject(): inserting with fqn: /a/b
              07/09 09:43:38,027 [main] DEBUG org.jboss.cache.transaction.DummyTransaction - processing beforeCompletion for tx=org.jboss.cache.transaction.DummyTransaction@1d85f79, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<192.168.11.105:33069>:1, tx=org.jboss.cache.transaction.DummyTransaction@1d85f79)]
              07/09 09:43:38,027 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Running beforeCompletion on gtx GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:38,029 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method prepare(GlobalTransaction:<192.168.11.105:33069>:1, [_put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b, _lock_, LOCK, true), _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b, {__jboss:internal:class__=class com.protagonis.cache.Student, AOPInstance=org.jboss.cache.aop.AOPInstance@12a3722, name=Name1, school=school1}, true), _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/address, {street=str, __jboss:internal:class__=class com.protagonis.cache.Address, AOPInstance=org.jboss.cache.aop.AOPInstance@89cf1e, zip=1, city=city}, true), _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/courses, __jboss:internal:class__, class java.util.LinkedHashSet, true), _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/courses, AOPInstance, org.jboss.cache.aop.AOPInstance@1f17e77, true)], 192.168.11.105:33069, false)
              07/09 09:43:38,029 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - bypassed locking as method prepare() doesn't require locking
              07/09 09:43:38,029 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Suppressing invocation of method prepare(GlobalTransaction:<192.168.11.105:33069>:1, [_put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b, _lock_, LOCK, true), _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b, {__jboss:internal:class__=class com.protagonis.cache.Student, AOPInstance=org.jboss.cache.aop.AOPInstance@12a3722, name=Name1, school=school1}, true), _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/address, {street=str, __jboss:internal:class__=class com.protagonis.cache.Address, AOPInstance=org.jboss.cache.aop.AOPInstance@89cf1e, zip=1, city=city}, true), _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/courses, __jboss:internal:class__, class java.util.LinkedHashSet, true), _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/courses, AOPInstance, org.jboss.cache.aop.AOPInstance@1f17e77, true)], 192.168.11.105:33069, false) on cache.
              07/09 09:43:38,030 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - (192.168.11.105:33069): running remote prepare for global tx GlobalTransaction:<192.168.11.105:33069>:1 with async mode=false
              07/09 09:43:38,030 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Broadcasting call prepare(GlobalTransaction:<192.168.11.105:33069>:1, [_put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b, _lock_, LOCK, true), _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b, {__jboss:internal:class__=class com.protagonis.cache.Student, AOPInstance=org.jboss.cache.aop.AOPInstance@12a3722, name=Name1, school=school1}, true), _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/address, {street=str, __jboss:internal:class__=class com.protagonis.cache.Address, AOPInstance=org.jboss.cache.aop.AOPInstance@89cf1e, zip=1, city=city}, true), _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/courses, __jboss:internal:class__, class java.util.LinkedHashSet, true), _put(GlobalTransaction:<192.168.11.105:33069>:1, /a/b/courses, AOPInstance, org.jboss.cache.aop.AOPInstance@1f17e77, true)], 192.168.11.105:33069, false) to recipient list null
              07/09 09:43:38,030 [main] DEBUG org.jboss.cache.TreeCache - destination list is empty, discarding call
              07/09 09:43:38,030 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - responses=null
              07/09 09:43:38,030 [main] DEBUG org.jboss.cache.transaction.DummyTransaction - processing beforeCompletion for org.jboss.cache.aop.PojoTxSynchronizationHandler@10e3293
              07/09 09:43:38,030 [main] DEBUG org.jboss.cache.transaction.DummyTransaction - processing afterCompletion for tx=org.jboss.cache.transaction.DummyTransaction@1d85f79, handlers=[TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<192.168.11.105:33069>:1, tx=org.jboss.cache.transaction.DummyTransaction@1d85f79)]
              07/09 09:43:38,030 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - calling aftercompletion for GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:38,031 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Running commit phase. One phase? false
              07/09 09:43:38,031 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - running commit for GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:38,031 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Broadcasting call commit(GlobalTransaction:<192.168.11.105:33069>:1) to recipient list null
              07/09 09:43:38,031 [main] DEBUG org.jboss.cache.TreeCache - destination list is empty, discarding call
              07/09 09:43:38,031 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - responses=null
              07/09 09:43:38,031 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method commit(GlobalTransaction:<192.168.11.105:33069>:1)
              07/09 09:43:38,031 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - committing cache with gtx GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:38,031 [main] DEBUG org.jboss.cache.TransactionEntry - releasing lock for /a/b/courses (write owner=GlobalTransaction:<192.168.11.105:33069>:1)
              07/09 09:43:38,032 [main] DEBUG org.jboss.cache.TransactionEntry - releasing lock for /a/b (write owner=GlobalTransaction:<192.168.11.105:33069>:1)
              07/09 09:43:38,032 [main] DEBUG org.jboss.cache.TransactionEntry - releasing lock for /a (read owners=[GlobalTransaction:<192.168.11.105:33069>:1])
              07/09 09:43:38,032 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - removing local transaction org.jboss.cache.transaction.DummyTransaction@1d85f79 and global transaction GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:38,032 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - bypassed locking as method commit() doesn't require locking
              07/09 09:43:38,032 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Suppressing invocation of method commit(GlobalTransaction:<192.168.11.105:33069>:1) on cache.
              07/09 09:43:38,032 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {}
              07/09 09:43:38,032 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Finished local commit/rollback method for GlobalTransaction:<192.168.11.105:33069>:1
              07/09 09:43:38,032 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - Finished commit phase
              07/09 09:43:38,032 [main] DEBUG org.jboss.cache.transaction.DummyTransaction - processing afterCompletion for org.jboss.cache.aop.PojoTxSynchronizationHandler@10e3293
              07/09 09:43:38,032 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b", AOPInstance, "false")
              07/09 09:43:38,034 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b/address", AOPInstance, "false")
              07/09 09:43:38,034 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_get(/a/b/address, zip, true)]
              07/09 09:43:38,034 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _get(/a/b/address, zip, true)
              07/09 09:43:38,034 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /a/b/address for owner Thread[main,5,main]
              07/09 09:43:38,034 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a, caller=Thread[main,5,main], lock=
              07/09 09:43:38,034 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,034 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b, caller=Thread[main,5,main], lock=
              07/09 09:43:38,034 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,035 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b/address, caller=Thread[main,5,main], lock=
              07/09 09:43:38,035 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b/address, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,035 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _get(/a/b/address, zip, true) on cache.
              07/09 09:43:38,035 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b/address", zip, "true")
              07/09 09:43:38,035 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[main,5,main]=[read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]]]}
              07/09 09:43:38,035 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b/address: read owners=[Thread[main,5,main]]
              07/09 09:43:38,035 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b: read owners=[Thread[main,5,main]]
              07/09 09:43:38,035 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a: read owners=[Thread[main,5,main]]
              07/09 09:43:38,035 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Non-tx and non crud meth
              07/09 09:43:38,036 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_put(null, /a/b/address, zip, 2, true)]
              07/09 09:43:38,037 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _put(null, /a/b/address, zip, 2, true)
              07/09 09:43:38,037 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /a/b/address for owner Thread[main,5,main]
              07/09 09:43:38,037 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a, caller=Thread[main,5,main], lock=
              07/09 09:43:38,037 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,037 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b, caller=Thread[main,5,main], lock=
              07/09 09:43:38,037 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,037 [main] DEBUG org.jboss.cache.Node - acquiring WL: fqn=/a/b/address, caller=Thread[main,5,main], lock=
              07/09 09:43:38,037 [main] DEBUG org.jboss.cache.Node - acquired WL: fqn=/a/b/address, caller=Thread[main,5,main], lock=write owner=Thread[main,5,main]
              07/09 09:43:38,037 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _put(null, /a/b/address, zip, 2, true) on cache.
              07/09 09:43:38,038 [main] DEBUG org.jboss.cache.TreeCache - _put(null, "/a/b/address", zip, 2)
              07/09 09:43:38,038 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[main,5,main]=[read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], write owner=Thread[main,5,main]]}
              07/09 09:43:38,038 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b/address: write owner=Thread[main,5,main]
              07/09 09:43:38,038 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b: read owners=[Thread[main,5,main]]
              07/09 09:43:38,038 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a: read owners=[Thread[main,5,main]]
              07/09 09:43:38,039 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Non-tx crud meth
              07/09 09:43:38,039 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - invoking method _put(null, /a/b/address, zip, 2, true), members=[192.168.11.105:33069], mode=REPL_SYNC, exclude_self=true, timeout=15000
              07/09 09:43:38,039 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Broadcasting call _put(null, /a/b/address, zip, 2, true) to recipient list null
              07/09 09:43:38,039 [main] DEBUG org.jboss.cache.TreeCache - destination list is empty, discarding call
              07/09 09:43:38,039 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - responses=null
              07/09 09:43:38,039 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b", AOPInstance, "false")
              07/09 09:43:38,039 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b/address", AOPInstance, "false")
              07/09 09:43:38,039 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_get(/a/b/address, zip, true)]
              07/09 09:43:38,039 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _get(/a/b/address, zip, true)
              07/09 09:43:38,039 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /a/b/address for owner Thread[main,5,main]
              07/09 09:43:38,040 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a, caller=Thread[main,5,main], lock=
              07/09 09:43:38,040 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,040 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b, caller=Thread[main,5,main], lock=
              07/09 09:43:38,040 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,040 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b/address, caller=Thread[main,5,main], lock=
              07/09 09:43:38,040 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b/address, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,040 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _get(/a/b/address, zip, true) on cache.
              07/09 09:43:38,040 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b/address", zip, "true")
              07/09 09:43:38,040 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[main,5,main]=[read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]]]}
              07/09 09:43:38,040 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b/address: read owners=[Thread[main,5,main]]
              07/09 09:43:38,040 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b: read owners=[Thread[main,5,main]]
              07/09 09:43:38,041 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a: read owners=[Thread[main,5,main]]
              07/09 09:43:38,041 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Non-tx and non crud meth
              07/09 09:43:38,041 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_put(null, /a/b/address, zip, 3, true)]
              07/09 09:43:38,041 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _put(null, /a/b/address, zip, 3, true)
              07/09 09:43:38,041 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /a/b/address for owner Thread[main,5,main]
              07/09 09:43:38,041 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a, caller=Thread[main,5,main], lock=
              07/09 09:43:38,041 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,041 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b, caller=Thread[main,5,main], lock=
              07/09 09:43:38,041 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,041 [main] DEBUG org.jboss.cache.Node - acquiring WL: fqn=/a/b/address, caller=Thread[main,5,main], lock=
              07/09 09:43:38,041 [main] DEBUG org.jboss.cache.Node - acquired WL: fqn=/a/b/address, caller=Thread[main,5,main], lock=write owner=Thread[main,5,main]
              07/09 09:43:38,042 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _put(null, /a/b/address, zip, 3, true) on cache.
              07/09 09:43:38,042 [main] DEBUG org.jboss.cache.TreeCache - _put(null, "/a/b/address", zip, 3)
              07/09 09:43:38,042 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[main,5,main]=[read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], write owner=Thread[main,5,main]]}
              07/09 09:43:38,042 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b/address: write owner=Thread[main,5,main]
              07/09 09:43:38,042 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b: read owners=[Thread[main,5,main]]
              07/09 09:43:38,042 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a: read owners=[Thread[main,5,main]]
              07/09 09:43:38,042 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Non-tx crud meth
              07/09 09:43:38,042 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - invoking method _put(null, /a/b/address, zip, 3, true), members=[192.168.11.105:33069], mode=REPL_SYNC, exclude_self=true, timeout=15000
              07/09 09:43:38,042 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Broadcasting call _put(null, /a/b/address, zip, 3, true) to recipient list null
              07/09 09:43:38,042 [main] DEBUG org.jboss.cache.TreeCache - destination list is empty, discarding call
              07/09 09:43:38,042 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - responses=null
              07/09 09:43:38,042 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b", AOPInstance, "false")
              07/09 09:43:38,043 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b/address", AOPInstance, "false")
              07/09 09:43:38,043 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_get(/a/b/address, zip, true)]
              07/09 09:43:38,043 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _get(/a/b/address, zip, true)
              07/09 09:43:38,043 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /a/b/address for owner Thread[main,5,main]
              07/09 09:43:38,043 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a, caller=Thread[main,5,main], lock=
              07/09 09:43:38,043 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,043 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b, caller=Thread[main,5,main], lock=
              07/09 09:43:38,043 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,043 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b/address, caller=Thread[main,5,main], lock=
              07/09 09:43:38,043 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b/address, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,043 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _get(/a/b/address, zip, true) on cache.
              07/09 09:43:38,044 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b/address", zip, "true")
              07/09 09:43:38,044 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[main,5,main]=[read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]]]}
              07/09 09:43:38,044 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b/address: read owners=[Thread[main,5,main]]
              07/09 09:43:38,044 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b: read owners=[Thread[main,5,main]]
              07/09 09:43:38,044 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a: read owners=[Thread[main,5,main]]
              07/09 09:43:38,044 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Non-tx and non crud meth
              07/09 09:43:38,044 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_put(null, /a/b/address, zip, 4, true)]
              07/09 09:43:38,044 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _put(null, /a/b/address, zip, 4, true)
              07/09 09:43:38,045 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /a/b/address for owner Thread[main,5,main]
              07/09 09:43:38,045 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a, caller=Thread[main,5,main], lock=
              07/09 09:43:38,045 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,045 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b, caller=Thread[main,5,main], lock=
              07/09 09:43:38,045 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,045 [main] DEBUG org.jboss.cache.Node - acquiring WL: fqn=/a/b/address, caller=Thread[main,5,main], lock=
              07/09 09:43:38,045 [main] DEBUG org.jboss.cache.Node - acquired WL: fqn=/a/b/address, caller=Thread[main,5,main], lock=write owner=Thread[main,5,main]
              07/09 09:43:38,045 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _put(null, /a/b/address, zip, 4, true) on cache.
              07/09 09:43:38,045 [main] DEBUG org.jboss.cache.TreeCache - _put(null, "/a/b/address", zip, 4)
              07/09 09:43:38,045 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[main,5,main]=[read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], write owner=Thread[main,5,main]]}
              07/09 09:43:38,045 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b/address: write owner=Thread[main,5,main]
              07/09 09:43:38,046 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b: read owners=[Thread[main,5,main]]
              07/09 09:43:38,046 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a: read owners=[Thread[main,5,main]]
              07/09 09:43:38,046 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Non-tx crud meth
              07/09 09:43:38,046 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - invoking method _put(null, /a/b/address, zip, 4, true), members=[192.168.11.105:33069], mode=REPL_SYNC, exclude_self=true, timeout=15000
              07/09 09:43:38,046 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Broadcasting call _put(null, /a/b/address, zip, 4, true) to recipient list null
              07/09 09:43:38,046 [main] DEBUG org.jboss.cache.TreeCache - destination list is empty, discarding call
              07/09 09:43:38,046 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - responses=null
              07/09 09:43:38,046 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b", AOPInstance, "false")
              07/09 09:43:38,047 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b/address", AOPInstance, "false")
              07/09 09:43:38,047 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_get(/a/b/address, zip, true)]
              07/09 09:43:38,047 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _get(/a/b/address, zip, true)
              07/09 09:43:38,047 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /a/b/address for owner Thread[main,5,main]
              07/09 09:43:38,047 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a, caller=Thread[main,5,main], lock=
              07/09 09:43:38,047 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,047 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b, caller=Thread[main,5,main], lock=
              07/09 09:43:38,047 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,048 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b/address, caller=Thread[main,5,main], lock=
              07/09 09:43:38,048 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b/address, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,048 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _get(/a/b/address, zip, true) on cache.
              07/09 09:43:38,048 [main] DEBUG org.jboss.cache.TreeCache - _get("/a/b/address", zip, "true")
              07/09 09:43:38,049 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[main,5,main]=[read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]]]}
              07/09 09:43:38,049 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b/address: read owners=[Thread[main,5,main]]
              07/09 09:43:38,049 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b: read owners=[Thread[main,5,main]]
              07/09 09:43:38,049 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a: read owners=[Thread[main,5,main]]
              07/09 09:43:38,049 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Non-tx and non crud meth
              07/09 09:43:38,049 [main] DEBUG org.jboss.cache.interceptors.TxInterceptor - (192.168.11.105:33069) call on method [_put(null, /a/b/address, zip, 5, true)]
              07/09 09:43:38,049 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _put(null, /a/b/address, zip, 5, true)
              07/09 09:43:38,050 [main] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /a/b/address for owner Thread[main,5,main]
              07/09 09:43:38,050 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a, caller=Thread[main,5,main], lock=
              07/09 09:43:38,050 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,050 [main] DEBUG org.jboss.cache.Node - acquiring RL: fqn=/a/b, caller=Thread[main,5,main], lock=
              07/09 09:43:38,050 [main] DEBUG org.jboss.cache.Node - acquired RL: fqn=/a/b, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
              07/09 09:43:38,050 [main] DEBUG org.jboss.cache.Node - acquiring WL: fqn=/a/b/address, caller=Thread[main,5,main], lock=
              07/09 09:43:38,050 [main] DEBUG org.jboss.cache.Node - acquired WL: fqn=/a/b/address, caller=Thread[main,5,main], lock=write owner=Thread[main,5,main]
              07/09 09:43:38,050 [main] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _put(null, /a/b/address, zip, 5, true) on cache.
              07/09 09:43:38,050 [main] DEBUG org.jboss.cache.TreeCache - _put(null, "/a/b/address", zip, 5)
              07/09 09:43:38,054 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {Thread[main,5,main]=[read owners=[Thread[main,5,main]], read owners=[Thread[main,5,main]], write owner=Thread[main,5,main]]}
              07/09 09:43:38,054 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b/address: write owner=Thread[main,5,main]
              07/09 09:43:38,054 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a/b: read owners=[Thread[main,5,main]]
              07/09 09:43:38,054 [main] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /a: read owners=[Thread[main,5,main]]
              07/09 09:43:38,055 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Non-tx crud meth
              07/09 09:43:38,055 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - invoking method _put(null, /a/b/address, zip, 5, true), members=[192.168.11.105:33069], mode=REPL_SYNC, exclude_self=true, timeout=15000
              07/09 09:43:38,055 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Broadcasting call _put(null, /a/b/address, zip, 5, true) to recipient list null
              07/09 09:43:38,055 [main] DEBUG org.jboss.cache.TreeCache - destination list is empty, discarding call
              07/09 09:43:38,055 [main] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - responses=null
              07/09 09:43:38,058 [main] INFO com.protagonis.test.utils.Timing - Elapsed time: 550 millisec com.protagonis.cache.ManualTestCacheJbossExample.doAspect
              07/09 09:43:38,058 [main] DEBUG org.jboss.cache.aop.PojoCache - Stopping PojoCache
              07/09 09:43:38,058 [main] INFO org.jboss.cache.TreeCache - stopService(): closing the channel
              07/09 09:43:38,075 [main] INFO org.jboss.cache.TreeCache - stopService(): stopping the dispatcher
              07/09 09:43:38,075 [main] DEBUG org.jboss.cache.aop.PojoCache - Stopped PojoCache

                • Actions