Author: manik.surtani(a)jboss.com Date: 2008-10-01 10:21:25 -0400 (Wed, 01 Oct 2008) New Revision: 6822 Modified: core/branches/2.2.X/pom.xml core/branches/2.2.X/src/test/java/org/jboss/cache/profiling/ProfileTest.java core/branches/2.2.X/src/test/resources/log4j.xml Log: Updated pom Modified: core/branches/2.2.X/pom.xml =================================================================== --- core/branches/2.2.X/pom.xml 2008-10-01 14:20:42 UTC (rev 6821) +++ core/branches/2.2.X/pom.xml 2008-10-01 14:21:25 UTC (rev 6822) @@ -14,7 +14,7 @@ <parent> <groupId>org.jboss.cache</groupId> <artifactId>jbosscache-common-parent</artifactId> - <version>1.3</version> + <version>1.4</version> </parent> <groupId>org.jboss.cache</groupId> <artifactId>jbosscache-core</artifactId> @@ -27,7 +27,7 @@ <dependency> <groupId>jgroups</groupId> <artifactId>jgroups</artifactId> - <version>2.6.3.GA</version> + <version>2.6.4.GA</version> </dependency> <!-- For the JTA 1.1 API; consuming projects can safely @@ -419,7 +419,7 @@ <dependency> <groupId>jgroups</groupId> <artifactId>jgroups</artifactId> - <version>2.6.3.GA</version> + <version>2.6.4.GA</version> </dependency> <!-- Replaces javax.transaction/jta --> <dependency> Modified: core/branches/2.2.X/src/test/java/org/jboss/cache/profiling/ProfileTest.java =================================================================== --- core/branches/2.2.X/src/test/java/org/jboss/cache/profiling/ProfileTest.java 2008-10-01 14:20:42 UTC (rev 6821) +++ core/branches/2.2.X/src/test/java/org/jboss/cache/profiling/ProfileTest.java 2008-10-01 14:21:25 UTC (rev 6822) @@ -17,6 +17,7 @@ import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicLong; /** * Test to use with a profiler to profile replication. To be used in conjunction with ProfileSlaveTest. @@ -38,10 +39,10 @@ Test configuration options */ protected static final long NUM_OPERATIONS = 1000000; // DURATION is replaced with a fixed number of operations instead. - protected static final int NUM_THREADS = 1; + protected static final int NUM_THREADS = 25; protected static final int MAX_RANDOM_SLEEP_MILLIS = 1; protected static final int MAX_DEPTH = 3; - protected static final int MAX_OVERALL_NODES = 200; + protected static final int MAX_OVERALL_NODES = 50; protected static final int WARMUP_LOOPS = 20000; protected static final boolean USE_SLEEP = false; // throttle generation a bit @@ -53,7 +54,7 @@ Log log = LogFactory.getLog(ProfileTest.class); - @Test(enabled = false) + @Test(enabled = true) public void testLocalModePess() throws Exception { cache.getConfiguration().setCacheMode(Configuration.CacheMode.LOCAL); @@ -243,27 +244,31 @@ startup(); } - private void doTest() throws Exception +private void doTest() throws Exception { ExecutorService exec = Executors.newFixedThreadPool(NUM_THREADS); - // Executor exec = new DirectExecutor(); - long startTime = System.currentTimeMillis(); log.warn("Starting test"); int i; long print = NUM_OPERATIONS / 10; + + AtomicLong durationPuts = new AtomicLong(); + AtomicLong durationGets = new AtomicLong(); + AtomicLong durationRemoves = new AtomicLong(); + + long stElapsed = System.nanoTime(); for (i = 0; i < NUM_OPERATIONS; i++) { MyRunnable r = null; switch (i % 3) { case 0: - r = new Putter(i); + r = new Putter(i, durationPuts); break; case 1: - r = new Getter(i); + r = new Getter(i, durationGets); break; case 2: - r = new Remover(i); + r = new Remover(i, durationRemoves); break; } if (i % print == 0) @@ -275,12 +280,28 @@ log.warn("Finished generating runnables; awaiting executor completion"); // wait for executors to complete! exec.shutdown(); - exec.awaitTermination(((long) i), TimeUnit.SECONDS); // wait up to 1 sec for each call? - long duration = System.currentTimeMillis() - startTime; - log.warn("Finished test. " + printDuration(duration)); - log.warn("Throughput: " + (NUM_OPERATIONS * 1000 / duration) + " operations per second (roughly equal numbers of PUT, GET and REMOVE)"); + while (!exec.awaitTermination(((long) i), TimeUnit.SECONDS)) {Thread.sleep(1);} // wait up to 1 sec for each call? + long elapsedTimeNanos = System.nanoTime() - stElapsed; + + log.warn("Finished test. " + printDuration((long) toMillis(elapsedTimeNanos))); + log.warn("Throughput: " + ((double) NUM_OPERATIONS * 1000 / toMillis(elapsedTimeNanos)) + " operations per second (roughly equal numbers of PUT, GET and REMOVE)"); + log.warn("Average GET time: " + printAvg(durationGets.get())); + log.warn("Average PUT time: " + printAvg(durationPuts.get())); + log.warn("Average REMOVE time: " + printAvg(durationRemoves.get())); } + private String printAvg(long totalNanos) + { + double nOps = (double) (NUM_OPERATIONS / 3); + double avg = ((double) totalNanos) / nOps; + double avgMicros = avg / 1000; + return avgMicros + " �s"; + } + + private double toMillis(long nanos) + { + return ((double) nanos / (double) 1000000); + } enum Mode { PUT, GET, REMOVE @@ -290,53 +311,61 @@ { int id; Mode mode; + AtomicLong duration; - public void run() { String k = getRandomString(); Fqn f = fqns.get(r.nextInt(MAX_OVERALL_NODES)); + long d = 0, st = 0; switch (mode) { case PUT: + st = System.nanoTime(); cache.put(f, k, getRandomString()); - // cache.put(BELAS_FQN, BELAS_KEY, new byte[10000]); + d = System.nanoTime() - st; break; case GET: - // cache.get(BELAS_FQN, BELAS_KEY); + st = System.nanoTime(); cache.get(f, k); + d = System.nanoTime() - st; break; case REMOVE: - // cache.remove(BELAS_FQN, BELAS_KEY); + st = System.nanoTime(); cache.remove(f, k); + d = System.nanoTime() - st; break; } + duration.getAndAdd(d); } } private class Putter extends MyRunnable { - private Putter(int id) + private Putter(int id, AtomicLong duration) { this.id = id; + this.duration = duration; mode = Mode.PUT; } } private class Getter extends MyRunnable { - private Getter(int id) + private Getter(int id, AtomicLong duration) { this.id = id; + this.duration = duration; mode = Mode.GET; } } private class Remover extends MyRunnable { - private Remover(int id) + private Remover(int id, AtomicLong duration) { this.id = id; + this.duration = duration; mode = Mode.REMOVE; } } Modified: core/branches/2.2.X/src/test/resources/log4j.xml =================================================================== --- core/branches/2.2.X/src/test/resources/log4j.xml 2008-10-01 14:20:42 UTC (rev 6821) +++ core/branches/2.2.X/src/test/resources/log4j.xml 2008-10-01 14:21:25 UTC (rev 6822) @@ -66,8 +66,8 @@ <!-- ======================= --> <root> - <appender-ref ref="FILE"/> - <!--<appender-ref ref="CONSOLE"/>--> + <!--<appender-ref ref="FILE"/>--> + <appender-ref ref="CONSOLE"/> </root> </log4j:configuration>