added comments
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/8dd1868a Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/8dd1868a Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/8dd1868a Branch: refs/heads/LOG4j2-494 Commit: 8dd1868ac9b941b8681059f47d279712e38790e8 Parents: d816108 Author: rpopma <[email protected]> Authored: Thu Apr 21 14:42:30 2016 +0900 Committer: Ralph Goers <[email protected]> Committed: Mon Apr 25 21:30:28 2016 -0700 ---------------------------------------------------------------------- .../core/async/perftest/SimpleLatencyTest.java | 17 +++++++++++------ 1 file changed, 11 insertions(+), 6 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/8dd1868a/log4j-core/src/test/java/org/apache/logging/log4j/core/async/perftest/SimpleLatencyTest.java ---------------------------------------------------------------------- diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/async/perftest/SimpleLatencyTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/async/perftest/SimpleLatencyTest.java index 8665d5d..ff2de75 100644 --- a/log4j-core/src/test/java/org/apache/logging/log4j/core/async/perftest/SimpleLatencyTest.java +++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/async/perftest/SimpleLatencyTest.java @@ -45,6 +45,7 @@ public class SimpleLatencyTest { final int threadCount = Integer.parseInt(args[0]); final int intervalMicros = Integer.parseInt(args[1]); + // print to console if ringbuffer is full System.setProperty("log4j2.AsyncEventRouter", PrintingDefaultAsyncEventRouter.class.getName()); System.setProperty("AsyncLogger.RingBufferSize", String.valueOf(256 * 1024)); System.setProperty("Log4jContextSelector", AsyncLoggerContextSelector.class.getName()); @@ -60,6 +61,7 @@ public class SimpleLatencyTest { final long interval = TimeUnit.MICROSECONDS.toNanos(intervalMicros);// * threadCount; System.out.printf("%d threads, interval is %d nanos%n", threadCount, interval); + // Warmup: run as many iterations of 50,000 calls to logger.log as we can in 1 minute final long WARMUP_DURATION_MILLIS = TimeUnit.MINUTES.toMillis(1); List<Histogram> warmupHistograms = new ArrayList<>(threadCount); @@ -69,6 +71,7 @@ public class SimpleLatencyTest { System.out.println("Warmup done."); Thread.sleep(1000); + // Actual test: run as many iterations of 5,000,000 calls to logger.log as we can in 4 minutes. long start = System.currentTimeMillis(); List<Histogram> histograms = new ArrayList<>(threadCount); @@ -77,6 +80,7 @@ public class SimpleLatencyTest { runLatencyTest(logger, TEST_DURATION_MILLIS, COUNT, interval, idleStrategy, histograms, nanoTimeCost, threadCount); long end = System.currentTimeMillis(); + // ... and report the results final Histogram result = new Histogram(TimeUnit.SECONDS.toNanos(10), 3); for (Histogram hist : histograms) { result.add(hist); @@ -86,9 +90,8 @@ public class SimpleLatencyTest { } public static void runLatencyTest(final Logger logger, final long durationMillis, final int samples, - final long intervalNanos, - final IdleStrategy idleStrategy, final List<Histogram> histograms, final long nanoTimeCost, - final int threadCount) throws InterruptedException { + final long intervalNanos, final IdleStrategy idleStrategy, final List<Histogram> histograms, + final long nanoTimeCost, final int threadCount) throws InterruptedException { Thread[] threads = new Thread[threadCount]; final CountDownLatch LATCH = new CountDownLatch(threadCount); @@ -100,9 +103,9 @@ public class SimpleLatencyTest { public void run() { LATCH.countDown(); try { - LATCH.await(); + LATCH.await(); // wait until all threads are ready to go } catch (InterruptedException e) { - interrupt(); // restore interrupt status + interrupt(); return; } long start = System.currentTimeMillis(); @@ -118,7 +121,9 @@ public class SimpleLatencyTest { } } - private static void runLatencyTest(int samples, Logger logger, long nanoTimeCost, Histogram hist, long intervalNanos, IdleStrategy idleStrategy) { + private static void runLatencyTest(int samples, Logger logger, long nanoTimeCost, Histogram hist, + long intervalNanos, IdleStrategy idleStrategy) { + for (int i = 0; i < samples; i++) { final long s1 = System.nanoTime(); logger.info(LATENCY_MSG);
