Thursday, October 28, 2010

Coherence: One thread is not enough!


You inform me, that no Part must be missing if the finest Effects are to be had, but you can not but know how hard it is to be sure.


- "The Case of Charles Dexter Ward", H.P. Lovecraft
It surprised me no end to find out that the when using a Distributed Cache for Coherence, the default number of daemon threads used to process incoming requests was zero, meaning that all work is performed on the service thread for that cache. This will make a major impact when you are using a cache to handle a large number of concurrent requests. Fortunately, it's not hard to fix this.

My demonstration code is based off the initial code used for my last entry, with just a few modifications to better illustrate what's happening. First, we'll add five seconds to the time it takes for TimeAndSpace to process a summoning request from a Cultist.
public static String processSummoning(Cultist cultist) {
      try {
        Thread.sleep(5000);
      }
      catch (InterruptedException e) {
        Thread.currentThread().interrupt();
      }
      // While not pertinent to the result, the name is used ... in this case for output.
      System.out.println("TimeAndSpace: Processing summoning by " + cultist.getName() + " for " + cultist.getAncientOne());
      return responseMap.get(cultist.getAncientOne());
    }

TimeAndSpace changes:
  • Each request will sleep for 5 seconds before returning.
Next, we arrange to have our cultists coordinate their summonings:
public static void main(String... args) {
    final NamedCache fhtagnCache = CacheFactory.getCache(CACHE);

    final long baseTime = System.currentTimeMillis();
    ScheduledExecutorService pool = Executors.newScheduledThreadPool(20);
    final CountDownLatch latch = new CountDownLatch(10);
    long startTime = System.currentTimeMillis();
    for (String ancientOne: ANCIENT_ONES) {
      // will make five calls
      for (int i = 0; i < 5; i++) {
        final Cultist cultist = new Cultist();
        cultist.setAncientOne(ancientOne);
        cultist.setName("Cultist " + System.currentTimeMillis());
        pool.schedule(new Runnable() {
          @Override
          public void run() {
            fhtagnCache.get(cultist);
            latch.countDown();
          }
        }, 100 - (System.currentTimeMillis() - baseTime), TimeUnit.MILLISECONDS);
      }
    }
    try {
      latch.await();
    }
    catch (InterruptedException e) {
      // don't know who would be interrupting...
      Thread.currentThread().interrupt();
    }
    long totalTime = System.currentTimeMillis() - startTime;
    System.out.println("Summoning time for 2 AOs: " + totalTime);
    pool.shutdownNow();
  }
KeyRitual changes:
  • A scheduled thread pool is set up to run the summonings in parallel, all starting at roughly the same time.
  • Each Ancient One will be summoned by five cultists.
  • Various items marked as final to allow them to be used in Runnable.
  • We output the total time taken to get a response for each summoning.
Given that it takes five seconds to process a summoning and that all calls are happening in separate threads, we would hope that the summonings should complete in a little over five seconds. However, running the code gives:
codefhtagn: javac -cp coherence.jar *.java
codefhtagn: java -cp coherence.jar:. -Dtangosol.coherence.cacheconfig=coherence-fhtagn.xml KeyRitual
... lines omitted ... 
TimeAndSpace: Processing summoning by Cultist 1288281586409 for Cthulhu
TimeAndSpace: Processing summoning by Cultist 1288281586407 for Cthulhu
TimeAndSpace: Processing summoning by Cultist 1288281586411 for Yog-Sothoth
TimeAndSpace: Processing summoning by Cultist 1288281586408 for Cthulhu
TimeAndSpace: Processing summoning by Cultist 1288281586410 for Yog-Sothoth
TimeAndSpace: Processing summoning by Cultist 1288281586410 for Cthulhu
Summoning time for 2 AOs: 30132
The total time is over thirty seconds, instead of five seconds, so clearly the single service thread is slowing us down. For those wondering why the time is not closer to ten seconds (five seconds per entry added to the cache) the answer is simple: every cache miss added five seconds since we had just one thread. While the number of misses can vary per run (in this case there were six misses, four for Cthulhu and two for Yog-Sothoth), at a minimum you will see two (I never observed less than four over multiple runs). So the best we can hope for is ten seconds total time, the worst can be much more more if we there are a lot of simultaneous requests for an entry that hasn't been added to the cache yet. Forturnately, as noted earlier, adding in multiple threads is a simple fix:
<thread-count>10</thread-count>
    </distributed-scheme>
coherencefhtagn.xml changes:
  • One additional node under distributed scheme specifying number of worker threads.
Now when we run we see:
codefhtagn: javac -cp coherence.jar *.java
codefhtagn: java -cp coherence.jar:. -Dtangosol.coherence.cacheconfig=coherence-fhtagn.xml KeyRitual
... lines omitted ... 
TimeAndSpace: Processing summoning by Cultist 1288285012455 for Yog-Sothoth
TimeAndSpace: Processing summoning by Cultist 1288285012454 for Cthulhu
TimeAndSpace: Processing summoning by Cultist 1288285012454 for Yog-Sothoth
TimeAndSpace: Processing summoning by Cultist 1288285012453 for Cthulhu
TimeAndSpace: Processing summoning by Cultist 1288285012451 for Cthulhu
Summoning time for 2 AOs: 5153
Even though this time there were five cache misses, the total time was still a little over five seconds because the requests were processed in parallel. Much better!

It's worth noting that the Coherenece's use of zero as a default for the number of daemon threads is used for more than just Distributed Caches. As far as I can tell, if there is a place where you can specify number of threads, then the default is zero (e.g. service thread does all the work). In particular, if you are using CoherenceExtend to connect to a cluster, then you will want to specify a number of threads to use, otherwise all of your requests to the cluster will get funnelled through a single service thread for the proxy.

No comments:

Post a Comment