4 Replies Latest reply on Oct 27, 2010 9:55 AM by Craig Ching

    Inconsistent performance when loading a cache

    Craig Ching Newbie

      I'm finding that Infinispan's performance is mostly good, but I see "blips" of bad performance when creating lots of objects in a cache.  For instance, if I run the following code:

       

       

      System.out.println("Starting test.");
      long total_begin = System.currentTimeMillis();
      long begin = total_begin;
      cache.startBatch();
      long min = Integer.MAX_VALUE;
      long max = Integer.MIN_VALUE;
      for (int i = 0; i < 1000000; ++i) {
      String username = "User" + i;
      User u = new User(username, (i%2==0), username + " full name", username + "@test.com", "mypassword");
      long each = System.currentTimeMillis();
      cache.put(u.getUsername(), u);
      long current = System.currentTimeMillis() - each;
      if (current > max) {
      max = current;
      }
      if (current < min) {
      min = current;
      }
      if ((i + 1) % 1000 == 0) {
      cache.endBatch(true);
      System.out.println((i + 1) + " users in the cache.  " + (System.currentTimeMillis() - begin) + " ms. (min: " + min + ", max: " + max + ")");
      begin = System.currentTimeMillis();
      min = Integer.MAX_VALUE;
      max = Integer.MIN_VALUE;
      cache.startBatch();
      }
      }
      cache.endBatch(true);
      System.out.println("Total time for test: " + (System.currentTimeMillis() - total_begin) + " ms.");
      System.out.println("Cache size: " + cache.size());
      cache.stop();
      cache_mgr.stop();
      System.out.println("Cache is stopped, exiting.");

                     System.out.println("Starting test.");

                     long total_begin = System.currentTimeMillis();

                     long begin = total_begin;

       

                     cache.startBatch();

                    

                     long min = Integer.MAX_VALUE;

                     long max = Integer.MIN_VALUE;

       

                     for (int i = 0; i < 1000000; ++i) {

                          String username = "User" + i;

                         

                          User u = new User(username, (i%2==0), username + " full name", username + "@test.com", "mypassword");

       

                          long each = System.currentTimeMillis();

                          cache.put(u.getUsername(), u);

                          long current = System.currentTimeMillis() - each;

                         

                          if (current > max) {

                               max = current;

                          }

                         

                          if (current < min) {

                               min = current;

                          }

                         

                          if ((i + 1) % 1000 == 0) {

                               cache.endBatch(true);

                               System.out.println((i + 1) + " users in the cache.  " + (System.currentTimeMillis() - begin) + " ms. (min: " + min + ", max: " + max + ")");

                               begin = System.currentTimeMillis();

                               min = Integer.MAX_VALUE;

                               max = Integer.MIN_VALUE;

                               cache.startBatch();

                          }

                     }

                     cache.endBatch(true);

                     System.out.println("Total time for test: " + (System.currentTimeMillis() - total_begin) + " ms.");

                     System.out.println("Cache size: " + cache.size());

                     cache.stop();

                     cache_mgr.stop();

                     System.out.println("Cache is stopped, exiting.");

      I get output like this:
      821000 users in the cache.  189 ms. (min: 0, max: 2)
      822000 users in the cache.  188 ms. (min: 0, max: 1)
      823000 users in the cache.  265 ms. (min: 0, max: 92)
      824000 users in the cache.  2075028 ms. (min: 0, max: 2071584)
      825000 users in the cache.  1523 ms. (min: 0, max: 43)
      826000 users in the cache.  201 ms. (min: 0, max: 1)
      827000 users in the cache.  210 ms. (min: 0, max: 12)
      828000 users in the cache.  305 ms. (min: 0, max: 74)
      The "blip" I'm talking about is at 824000 users in the cache (there are other "blips" much earlier in the test, this one was just handy).  Just to clarify here too, 2075028 is the time it took to put the whole batch into the cache and max is the maximum time it took to put just one object in the cache.
      Anyone else see these "blips"?  I wouldn't be so concerned about this since loading a cache like this really isn't my use case, but I'm concerned that when I do get one loaded, it might take an inordinate amount of time to put just one object in the cache, and for a webapp, anything beyond a second or two tops is going to get flagged by someone.