You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by rg...@apache.org on 2013/04/01 05:51:23 UTC
svn commit: r1463078 [3/4] - in /logging/log4j/log4j2/trunk: ./
core/src/main/java/org/apache/logging/log4j/core/
core/src/main/java/org/apache/logging/log4j/core/appender/
core/src/main/java/org/apache/logging/log4j/core/config/
core/src/main/java/org...
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/appender/FastRollingFileAppenderTest.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/appender/FastRollingFileAppenderTest.java?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/appender/FastRollingFileAppenderTest.java (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/appender/FastRollingFileAppenderTest.java Mon Apr 1 03:51:21 2013
@@ -0,0 +1,44 @@
+package org.apache.logging.log4j.async.appender;
+
+import static org.junit.Assert.*;
+
+import java.io.BufferedReader;
+import java.io.File;
+import java.io.FileReader;
+
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.core.LifeCycle;
+import org.apache.logging.log4j.core.config.XMLConfigurationFactory;
+import org.junit.BeforeClass;
+import org.junit.Test;
+
+public class FastRollingFileAppenderTest {
+
+ @BeforeClass
+ public static void beforeClass() {
+ System.setProperty(XMLConfigurationFactory.CONFIGURATION_FILE_PROPERTY,
+ "FastRollingFileAppenderTest.xml");
+ }
+
+ @Test
+ public void testFlushAtEndOfBatch() throws Exception {
+ File f = new File("FastRollingFileAppenderTest.log");
+ // System.out.println(f.getAbsolutePath());
+ f.delete();
+ Logger log = LogManager.getLogger("com.foo.Bar");
+ String msg = "Message flushed with immediate flush=false";
+ log.info(msg);
+ ((LifeCycle) LogManager.getContext()).stop(); // stop async thread
+
+ BufferedReader reader = new BufferedReader(new FileReader(f));
+ String line1 = reader.readLine();
+ reader.close();
+ f.delete();
+ assertNotNull("line1", line1);
+ assertTrue("line1 correct", line1.contains(msg));
+
+ String location = "testFlushAtEndOfBatch";
+ assertTrue("no location", !line1.contains(location));
+ }
+}
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/config/AsyncLoggerConfigTest.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/config/AsyncLoggerConfigTest.java?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/config/AsyncLoggerConfigTest.java (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/config/AsyncLoggerConfigTest.java Mon Apr 1 03:51:21 2013
@@ -0,0 +1,49 @@
+package org.apache.logging.log4j.async.config;
+
+import static org.junit.Assert.*;
+
+import java.io.BufferedReader;
+import java.io.File;
+import java.io.FileReader;
+
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.core.LifeCycle;
+import org.apache.logging.log4j.core.config.XMLConfigurationFactory;
+import org.junit.BeforeClass;
+import org.junit.Test;
+
+public class AsyncLoggerConfigTest {
+
+ @BeforeClass
+ public static void beforeClass() {
+ System.setProperty(XMLConfigurationFactory.CONFIGURATION_FILE_PROPERTY,
+ "AsyncLoggerConfigTest.xml");
+ }
+
+ @Test
+ public void testAdditivity() throws Exception {
+ File f = new File("AsyncLoggerConfigTest.log");
+ // System.out.println(f.getAbsolutePath());
+ f.delete();
+ Logger log = LogManager.getLogger("com.foo.Bar");
+ String msg = "Additive logging: 2 for the price of 1!";
+ log.info(msg);
+ ((LifeCycle) LogManager.getContext()).stop(); // stop async thread
+
+ BufferedReader reader = new BufferedReader(new FileReader(f));
+ String line1 = reader.readLine();
+ String line2 = reader.readLine();
+ reader.close();
+ f.delete();
+ assertNotNull("line1", line1);
+ assertNotNull("line2", line2);
+ assertTrue("line1 correct", line1.contains(msg));
+ assertTrue("line2 correct", line2.contains(msg));
+
+ String location = "testAdditivity";
+ assertTrue("location",
+ line1.contains(location) || line2.contains(location));
+ }
+
+}
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/IPerfTestRunner.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/IPerfTestRunner.java?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/IPerfTestRunner.java (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/IPerfTestRunner.java Mon Apr 1 03:51:21 2013
@@ -0,0 +1,17 @@
+package org.apache.logging.log4j.async.perftest;
+
+import com.lmax.disruptor.collections.Histogram;
+
+public interface IPerfTestRunner {
+ static final String LINE100 = "ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz1234567890!\"#$%&'()-=^~|\\@`[]{};:+*,.<>/?_123456";
+ static final String THROUGHPUT_MSG = LINE100 + LINE100 + LINE100 + LINE100
+ + LINE100;
+ static final String LATENCY_MSG = "Short msg";
+
+ void runThroughputTest(int lines, Histogram histogram);
+
+ void runLatencyTest(int samples, Histogram histogram, long nanoTimeCost,
+ int threadCount);
+ void shutdown();
+ void log(String finalMessage);
+}
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/MTPerfTest.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/MTPerfTest.java?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/MTPerfTest.java (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/MTPerfTest.java Mon Apr 1 03:51:21 2013
@@ -0,0 +1,93 @@
+package org.apache.logging.log4j.async.perftest;
+
+import java.io.File;
+
+import com.lmax.disruptor.collections.Histogram;
+
+public class MTPerfTest extends PerfTest {
+
+ public static void main(String[] args) throws Exception {
+ new MTPerfTest().doMain(args);
+ }
+
+ @Override
+ public void runTestAndPrintResult(final IPerfTestRunner runner,
+ final String name, final int threadCount, String resultFile)
+ throws Exception {
+
+ // ThreadContext.put("aKey", "mdcVal");
+ PerfTest.println("Warming up the JVM...");
+ long t1 = System.nanoTime();
+
+ // warmup at least 2 rounds and at most 1 minute
+ final Histogram warmupHist = PerfTest.createHistogram();
+ final long stop = System.currentTimeMillis() + (60 * 1000);
+ Runnable run1 = new Runnable() {
+ public void run() {
+ for (int i = 0; i < 10; i++) {
+ final int LINES = PerfTest.throughput ? 50000 : 200000;
+ runTest(runner, LINES, null, warmupHist, 2);
+ if (i > 0 && System.currentTimeMillis() >= stop) {
+ return;
+ }
+ }
+ }
+ };
+ Thread thread1 = new Thread(run1);
+ Thread thread2 = new Thread(run1);
+ thread1.start();
+ thread2.start();
+ thread1.join();
+ thread2.join();
+
+ PerfTest.printf("Warmup complete in %.1f seconds%n",
+ (System.nanoTime() - t1) / (1000.0 * 1000.0 * 1000.0));
+ PerfTest.println("Waiting 10 seconds for buffers to drain warmup data...");
+ Thread.sleep(10000);
+ new File("perftest.log").delete();
+ new File("perftest.log").createNewFile();
+
+ PerfTest.println("Starting the main test...");
+ PerfTest.throughput = false;
+ multiThreadedTestRun(runner, name, threadCount, resultFile);
+
+ Thread.sleep(1000);
+ PerfTest.throughput = true;
+ multiThreadedTestRun(runner, name, threadCount, resultFile);
+ }
+
+ private void multiThreadedTestRun(final IPerfTestRunner runner,
+ final String name, final int threadCount, String resultFile)
+ throws Exception {
+
+ final Histogram[] histograms = new Histogram[threadCount];
+ for (int i = 0; i < histograms.length; i++) {
+ histograms[i] = PerfTest.createHistogram();
+ }
+ final int LINES = 256 * 1024;
+
+ Thread[] threads = new Thread[threadCount];
+ for (int i = 0; i < threads.length; i++) {
+ final Histogram histogram = histograms[i];
+ threads[i] = new Thread() {
+ public void run() {
+// int latencyCount = threadCount >= 16 ? 1000000 : 5000000;
+ int latencyCount = 5000000;
+ int count = PerfTest.throughput ? LINES / threadCount
+ : latencyCount;
+ runTest(runner, count, "end", histogram, threadCount);
+ }
+ };
+ }
+ for (Thread thread : threads) {
+ thread.start();
+ }
+ for (Thread thread : threads) {
+ thread.join();
+ }
+
+ for (Histogram histogram : histograms) {
+ PerfTest.reportResult(resultFile, name, histogram);
+ }
+ }
+}
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/PerfTest.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/PerfTest.java?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/PerfTest.java (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/PerfTest.java Mon Apr 1 03:51:21 2013
@@ -0,0 +1,168 @@
+package org.apache.logging.log4j.async.perftest;
+
+import java.io.FileWriter;
+import java.io.IOException;
+
+import com.lmax.disruptor.collections.Histogram;
+
+public class PerfTest {
+
+ private static final String LINE100 = "ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz1234567890!\"#$%&'()-=^~|\\@`[]{};:+*,.<>/?_123456";
+ public static final String LINE500 = LINE100 + LINE100 + LINE100 + LINE100
+ + LINE100;
+
+ static boolean verbose = false;
+ static boolean throughput;
+
+ // determine how long it takes to call System.nanoTime() (on average)
+ static long calcNanoTimeCost() {
+ final long iterations = 10000000;
+ long start = System.nanoTime();
+ long finish = start;
+
+ for (int i = 0; i < iterations; i++) {
+ finish = System.nanoTime();
+ }
+
+ if (finish <= start) {
+ throw new IllegalStateException();
+ }
+
+ finish = System.nanoTime();
+ return (finish - start) / iterations;
+ }
+
+ static Histogram createHistogram() {
+ long[] intervals = new long[31];
+ long intervalUpperBound = 1L;
+ for (int i = 0, size = intervals.length - 1; i < size; i++) {
+ intervalUpperBound *= 2;
+ intervals[i] = intervalUpperBound;
+ }
+
+ intervals[intervals.length - 1] = Long.MAX_VALUE;
+ return new Histogram(intervals);
+ }
+
+ public static void main(String[] args) throws Exception {
+ new PerfTest().doMain(args);
+ }
+
+ public void doMain(String[] args) throws Exception {
+ String runnerClass = args[0];
+ IPerfTestRunner runner = (IPerfTestRunner) Class.forName(runnerClass)
+ .newInstance();
+ String name = args[1];
+ String resultFile = args.length > 2 ? args[2] : null;
+ for (String arg : args) {
+ if ("-verbose".equalsIgnoreCase(arg)) {
+ verbose = true;
+ }
+ if ("-throughput".equalsIgnoreCase(arg)) {
+ throughput = true;
+ }
+ }
+ int threadCount = args.length > 2 ? Integer.parseInt(args[3]) : 3;
+ printf("Starting %s %s (%d)...%n", getClass().getSimpleName(), name,
+ threadCount);
+ runTestAndPrintResult(runner, name, threadCount, resultFile);
+ runner.shutdown();
+ System.exit(0);
+ }
+
+ public void runTestAndPrintResult(IPerfTestRunner runner,
+ final String name, int threadCount, String resultFile)
+ throws Exception {
+ Histogram warmupHist = createHistogram();
+
+ // ThreadContext.put("aKey", "mdcVal");
+ println("Warming up the JVM...");
+ long t1 = System.nanoTime();
+
+ // warmup at least 2 rounds and at most 1 minute
+ final long stop = System.currentTimeMillis() + (60 * 1000);
+ for (int i = 0; i < 10; i++) {
+ final int LINES = throughput ? 50000 : 200000;
+ runTest(runner, LINES, null, warmupHist, 1);
+ if (i > 0 && System.currentTimeMillis() >= stop) {
+ return;
+ }
+ }
+
+ printf("Warmup complete in %.1f seconds%n", (System.nanoTime() - t1)
+ / (1000.0 * 1000.0 * 1000.0));
+ println("Waiting 10 seconds for buffers to drain warmup data...");
+ Thread.sleep(10000);
+
+ println("Starting the main test...");
+ // test
+ throughput = false;
+ runSingleThreadedTest(runner, name, resultFile);
+
+ Thread.sleep(1000);
+
+ throughput = true;
+ runSingleThreadedTest(runner, name, resultFile);
+ }
+
+ private int runSingleThreadedTest(IPerfTestRunner runner, String name,
+ String resultFile) throws IOException {
+ Histogram latency = createHistogram();
+ final int LINES = throughput ? 50000 : 5000000;
+ runTest(runner, LINES, "end", latency, 1);
+ reportResult(resultFile, name, latency);
+ return LINES;
+ }
+
+ static void reportResult(String file, String name, Histogram histogram)
+ throws IOException {
+ String result = createSamplingReport(name, histogram);
+ println(result);
+
+ if (file != null) {
+ FileWriter writer = new FileWriter(file, true);
+ writer.write(result);
+ writer.write(System.getProperty("line.separator"));
+ writer.close();
+ }
+ }
+
+ static void printf(String msg, Object... objects) {
+ if (verbose) {
+ System.out.printf(msg, objects);
+ }
+ }
+
+ static void println(String msg) {
+ if (verbose) {
+ System.out.println(msg);
+ }
+ }
+
+ static String createSamplingReport(String name, Histogram histogram) {
+ Histogram data = histogram;
+ if (throughput) {
+ return data.getMax() + " operations/second";
+ }
+ String result = String.format(
+ "avg=%.0f 99%%=%d 99.99%%=%d sampleCount=%d", data.getMean(), //
+ data.getTwoNinesUpperBound(), //
+ data.getFourNinesUpperBound(), //
+ data.getCount() //
+ );
+ return result;
+ }
+
+ public void runTest(IPerfTestRunner runner, int lines, String finalMessage,
+ Histogram histogram, int threadCount) {
+ if (throughput) {
+ runner.runThroughputTest(lines, histogram);
+ } else {
+ long nanoTimeCost = calcNanoTimeCost();
+ runner.runLatencyTest(lines, histogram, nanoTimeCost, threadCount);
+ }
+ if (finalMessage != null) {
+ runner.log(finalMessage);
+ }
+ }
+}
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/PerfTestDriver.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/PerfTestDriver.java?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/PerfTestDriver.java (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/PerfTestDriver.java Mon Apr 1 03:51:21 2013
@@ -0,0 +1,435 @@
+package org.apache.logging.log4j.async.perftest;
+
+import java.io.BufferedReader;
+import java.io.File;
+import java.io.FileReader;
+import java.io.IOException;
+import java.io.InputStreamReader;
+import java.nio.CharBuffer;
+import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.List;
+
+public class PerfTestDriver {
+ static enum WaitStrategy {
+ Sleep, Yield, Block
+ };
+
+ static class Setup implements Comparable<Setup> {
+ private Class<?> _class;
+ private String _log4jConfig;
+ private String _name;
+ private String[] _systemProperties;
+ private int _threadCount;
+ private File _temp;
+ public Stats _stats;
+ private WaitStrategy _wait;
+ private String _runner;
+
+ public Setup(Class<?> klass, String runner, String name,
+ String log4jConfig, int threadCount, WaitStrategy wait,
+ String... systemProperties) throws IOException {
+ _class = klass;
+ _runner = runner;
+ _name = name;
+ _log4jConfig = log4jConfig;
+ _threadCount = threadCount;
+ _systemProperties = systemProperties;
+ _wait = wait;
+ _temp = File.createTempFile("log4jperformance", ".txt");
+ }
+
+ List<String> processArguments(String java) {
+ List<String> args = new ArrayList<String>();
+ args.add(java);
+ args.add("-server");
+ args.add("-Xms1g");
+ args.add("-Xmx1g");
+
+ // args.add("-XX:+UseParallelOldGC");
+ // args.add("-Xloggc:gc.log");
+ // args.add("-XX:+PrintGCTimeStamps");
+ // args.add("-XX:+PrintGCDetails");
+ // args.add("-XX:+PrintGCDateStamps");
+ // args.add("-XX:+PrintGCApplicationStoppedTime");
+ // args.add("-XX:+PrintGCApplicationConcurrentTime");
+ // args.add("-XX:+PrintSafepointStatistics");
+
+ args.add("-Dlog4j.configuration=" + _log4jConfig); // log4j1.2
+ args.add("-Dlog4j.configurationFile=" + _log4jConfig); // log4j2
+ args.add("-Dlogback.configurationFile=" + _log4jConfig);// logback
+
+ int ringBufferSize = getUserSpecifiedRingBufferSize();
+ if (ringBufferSize >= 128) {
+ args.add("-DAsyncLoggerConfig.RingBufferSize=" + ringBufferSize);
+ args.add("-DAsyncLogger.RingBufferSize=" + ringBufferSize);
+ }
+ args.add("-DAsyncLoggerConfig.WaitStrategy=" + _wait);
+ args.add("-DAsyncLogger.WaitStrategy=" + _wait);
+ if (_systemProperties != null) {
+ for (String property : _systemProperties) {
+ args.add(property);
+ }
+ }
+ args.add("-cp");
+ args.add(System.getProperty("java.class.path"));
+ args.add(_class.getName());
+ args.add(_runner);
+ args.add(_name);
+ args.add(_temp.getAbsolutePath());
+ args.add(String.valueOf(_threadCount));
+ return args;
+ }
+
+ private int getUserSpecifiedRingBufferSize() {
+ try {
+ return Integer.parseInt(System.getProperty("RingBufferSize",
+ "-1"));
+ } catch (Exception ignored) {
+ return -1;
+ }
+ }
+
+ ProcessBuilder latencyTest(String java) {
+ return new ProcessBuilder(processArguments(java));
+ }
+
+ ProcessBuilder throughputTest(String java) {
+ List<String> args = processArguments(java);
+ args.add("-throughput");
+ return new ProcessBuilder(args);
+ }
+
+ @Override
+ public int compareTo(Setup other) {
+ // largest ops/sec first
+ return (int) Math.signum(other._stats._averageOpsPerSec
+ - _stats._averageOpsPerSec);
+ }
+
+ public String description() {
+ String detail = _class.getSimpleName();
+ if (PerfTest.class == _class) {
+ detail = "single thread";
+ } else if (MTPerfTest.class == _class) {
+ detail = _threadCount + " threads";
+ }
+ String target = _runner.substring(_runner.indexOf(".Run") + 4);
+ return target + ": " + _name + " (" + detail + ")";
+ }
+ }
+
+ static class Stats {
+ int _count;
+ long _average;
+ long _pct99;
+ long _pct99_99;
+ double _latencyRowCount;
+ int _throughputRowCount;
+ private long _averageOpsPerSec;
+
+ // example line: avg=828 99%=1118 99.99%=5028 Count=3125
+ public Stats(String raw, int repeat) {
+ String[] lines = raw.split("[\\r\\n]+");
+ long totalOps = 0;
+ for (String line : lines) {
+ if (line.startsWith("avg")) {
+ _latencyRowCount++;
+ String[] parts = line.split(" ");
+ int i = 0;
+ _average += Long.parseLong(parts[i++].split("=")[1]);
+ _pct99 += Long.parseLong(parts[i++].split("=")[1]);
+ _pct99_99 += Long.parseLong(parts[i++].split("=")[1]);
+ _count += Integer.parseInt(parts[i++].split("=")[1]);
+ } else {
+ _throughputRowCount++;
+ String number = line.substring(0, line.indexOf(' '));
+ long opsPerSec = Long.parseLong(number);
+ totalOps += opsPerSec;
+ }
+ }
+ _averageOpsPerSec = totalOps / (int) _throughputRowCount;
+ }
+
+ public String toString() {
+ String fmt = "throughput: %,d ops/sec. latency(ns): avg=%.1f 99%% < %.1f 99.99%% < %.1f (%d samples)";
+ return String.format(fmt, _averageOpsPerSec, //
+ _average / _latencyRowCount, // mean latency
+ _pct99 / _latencyRowCount, // 99% observations less than
+ _pct99_99 / _latencyRowCount,// 99.99% observs less than
+ _count);
+ }
+ }
+
+ // single-threaded performance test
+ private static Setup s(String config, String runner, String name,
+ String... systemProperties) throws IOException {
+ WaitStrategy wait = WaitStrategy.valueOf(System.getProperty(
+ "WaitStrategy", "Block"));
+ return new Setup(PerfTest.class, runner, name, config, 1, wait,
+ systemProperties);
+ }
+
+ // single-threaded performance test
+ private static Setup m(String config, String runner, String name,
+ int threadCount, String... systemProperties) throws IOException {
+ WaitStrategy wait = WaitStrategy.valueOf(System.getProperty(
+ "WaitStrategy", "Block"));
+ return new Setup(MTPerfTest.class, runner, name, config, threadCount,
+ wait, systemProperties);
+ }
+
+ public static void main(String[] args) throws Exception {
+ final String ALL_ASYNC = "-DLog4jContextSelector=org.apache.logging.log4j.async.AsyncLoggerContextSelector";
+ final String CACHEDCLOCK = "-DAsyncLogger.Clock=CachedClock";
+ final String SYSCLOCK = "";
+ final String LOG12 = "org.apache.logging.log4j.async.perftest.RunLog4j1";
+ final String LOG20 = "org.apache.logging.log4j.async.perftest.RunLog4j2";
+ final String LOGBK = "org.apache.logging.log4j.async.perftest.RunLogback";
+
+ long start = System.nanoTime();
+ List<Setup> tests = new ArrayList<PerfTestDriver.Setup>();
+ tests.add(s("perf-logback.xml", LOGBK, "Sync"));
+ tests.add(s("perf-log4j12.xml", LOG12, "Sync"));
+ tests.add(s("perf3PlainNoLoc.xml", LOG20, "Sync"));
+ tests.add(s("perf-logback-async.xml", LOGBK, "Async Appender"));
+ tests.add(s("perf-log4j12-async.xml", LOG12, "Async Appender"));
+ tests.add(s("perf5AsyncApndNoLoc.xml", LOG20,
+ "Async Appender no location"));
+ tests.add(s("perf3PlainNoLoc.xml", LOG20, "All async no loc SysClock",
+ ALL_ASYNC, SYSCLOCK));
+ tests.add(s("perf7MixedNoLoc.xml", LOG20, "Mixed async no location"));
+
+ for (int i = 32; i <= 64; i *= 2) {
+ tests.add(m("perf-logback.xml", LOGBK, "Sync", i));
+ tests.add(m("perf-log4j12.xml", LOG12, "Sync", i));
+ tests.add(m("perf3PlainNoLoc.xml", LOG20, "Sync", i));
+ tests.add(m("perf-logback-async.xml", LOGBK, "Async Appender", i));
+ tests.add(m("perf-log4j12-async.xml", LOG12, "Async Appender", i));
+ tests.add(m("perf5AsyncApndNoLoc.xml", LOG20,
+ "Async Appender no location", i));
+ tests.add(m("perf3PlainNoLoc.xml", LOG20,
+ "All async no loc SysClock", i, ALL_ASYNC, SYSCLOCK));
+ tests.add(m("perf7MixedNoLoc.xml", LOG20,
+ "Mixed async no location", i));
+ }
+
+ // Setup[] tests = new Setup[] { //
+ // s("perf-logback.xml", LOGBK, "Sync"), //
+ // s("perf-log4j12.xml", LOG12, "Sync"), //
+ // s("perf3PlainNoLoc.xml", LOG20, "Sync"), //
+ // s("perf-logback-async.xml", LOGBK, "Async Appender"), //
+ // s("perf-log4j12-async.xml", LOG12, "Async Appender"), //
+ // s("perf5AsyncApndNoLoc.xml", LOG20,
+ // "Async Appender no location"),
+ // s("perf3PlainNoLoc.xml", LOG20, "All async no loc SysClock",
+ // ALL_ASYNC, SYSCLOCK), //
+ // s("perf7MixedNoLoc.xml", LOG20, "Mixed async no location"), //
+ //
+ // m("perf-log4j12-async.xml", LOG12, "Async Appender", 2), //
+ // m("perf-log4j12.xml", LOG12, "Sync", 2), //
+ // m("perf-logback.xml", LOGBK, "Sync", 2), //
+ // m("perf-logback-async.xml", LOGBK, "Async Appender", 2), //
+ // m("perf3PlainNoLoc.xml", LOG20, "Sync", 2), //
+ // m("perf3PlainNoLoc.xml", LOG20, "All async no loc CachedClock",
+ // 2, ALL_ASYNC, CACHEDCLOCK), //
+ // m("perf3PlainNoLoc.xml", LOG20, "All async no loc SysClock", 2,
+ // ALL_ASYNC, SYSCLOCK), //
+ //
+ // m("perf-log4j12-async.xml", LOG12, "Async Appender", 4), //
+ // m("perf-log4j12.xml", LOG12, "Sync", 4), //
+ // m("perf-logback.xml", LOGBK, "Sync", 4), //
+ // m("perf-logback-async.xml", LOGBK, "Async Appender", 4), //
+ // m("perf3PlainNoLoc.xml", LOG20, "Sync", 4), //
+ // m("perf3PlainNoLoc.xml", LOG20,
+ // "All async no loc CachedClock",
+ // 4, ALL_ASYNC, CACHEDCLOCK), //
+ // m("perf3PlainNoLoc.xml", LOG20, "All async no loc SysClock",
+ // 4,
+ // ALL_ASYNC, SYSCLOCK), //
+ //
+ // m("perf-log4j12-async.xml", LOG12, "Async Appender", 8), //
+ // m("perf-log4j12.xml", LOG12, "Sync", 8), //
+ // m("perf-logback.xml", LOGBK, "Sync", 8), //
+ // m("perf-logback-async.xml", LOGBK, "Async Appender", 8), //
+ // m("perf3PlainNoLoc.xml", LOG20, "Sync", 8), //
+ // m("perf3PlainNoLoc.xml", LOG20,
+ // "All async no loc CachedClock",
+ // 8, ALL_ASYNC, CACHEDCLOCK), //
+ // m("perf3PlainNoLoc.xml", LOG20, "All async no loc SysClock",
+ // 8,
+ // ALL_ASYNC, SYSCLOCK), //
+
+ // 2 threads
+ // m("perf5AsyncApndNoLoc.xml", LOG20,"Async Appender no location",
+ // 2), //
+ // m("perf6AsyncApndLoc.xml",
+ // LOG12,"Async Appender with location",
+ // 2), //
+ // m("perf7MixedNoLoc.xml", "Mixed async no location", 2), //
+ // m("perf8MixedLoc.xml", "Mixed async with location", 2), //
+ // m("perf4PlainLocation.xml",
+ // "All async with location SysClock",
+ // 2, ALL_ASYNC), //
+ // m("perf4PlainLocation.xml",
+ // "All async with location CachedClock", 2, ALL_ASYNC,
+ // CACHEDCLOCK), //
+ // m("perf4PlainLocation.xml", "All sync with location", 2), //
+ // m("perf1syncFile.xml", "FileAppender", 2), //
+ // m("perf1syncFastFile.xml", "FastFileAppender", 2), //
+ // m("perf2syncRollFile.xml", "RollFileAppender", 2), //
+ // m("perf2syncRollFastFile.xml", "RollFastFileAppender", 2), //
+
+ // 4 threads
+ // m("perf5AsyncApndNoLoc.xml", LOG20,"Async Appender no location",
+ // 4), //
+ // m("perf6AsyncApndLoc.xml", "Async Appender with location",
+ // 4), //
+ // m("perf7MixedNoLoc.xml", "Mixed async no location", 4), //
+ // m("perf8MixedLoc.xml", "Mixed async with location", 4), //
+ // m("perf4PlainLocation.xml",
+ // "All async with location SysClock",
+ // 4, ALL_ASYNC), //
+ // m("perf4PlainLocation.xml",
+ // "All async with location CachedClock", 4, ALL_ASYNC,
+ // CACHEDCLOCK), //
+ // m("perf4PlainLocation.xml", "All sync with location", 4), //
+ // m("perf1syncFile.xml", "FileAppender", 4), //
+ // m("perf1syncFastFile.xml", "FastFileAppender", 4), //
+ // m("perf2syncRollFile.xml", "RollFileAppender", 4), //
+ // m("perf2syncRollFastFile.xml", "RollFastFileAppender", 4), //
+
+ // 8 threads
+ // m("perf5AsyncApndNoLoc.xml", LOG20,
+ // "Async Appender no location", 8), //
+ // m("perf6AsyncApndLoc.xml", "Async Appender with location",
+ // 8), //
+ // m("perf7MixedNoLoc.xml", "Mixed async no location", 8), //
+ // m("perf8MixedLoc.xml", "Mixed async with location", 8), //
+ // m("perf4PlainLocation.xml",
+ // "All async with location SysClock",
+ // 8, ALL_ASYNC), //
+ // m("perf4PlainLocation.xml",
+ // "All async with location CachedClock", 8, ALL_ASYNC,
+ // CACHEDCLOCK), //
+ // m("perf4PlainLocation.xml", "All sync with location", 8), //
+ // m("perf1syncFile.xml", "FileAppender", 8), //
+ // m("perf1syncFastFile.xml", "FastFileAppender", 8), //
+ // m("perf2syncRollFile.xml", "RollFileAppender", 8), //
+ // m("perf2syncRollFastFile.xml", "RollFastFileAppender", 8), //
+
+ // s("perf-log4j12-async.xml", LOG12, "Async Appender"), //
+ // s("perf-log4j12.xml", LOG12, "Sync"), //
+ // s("perf-logback.xml", LOGBK, "Sync"), //
+ // s("perf-logback-async.xml", LOGBK, "Async Appender"), //
+ // s("perf3PlainNoLoc.xml", LOG20, "Sync"), //
+ // s("perf3PlainNoLoc.xml", LOG20, "All async no loc CachedClock",
+ // ALL_ASYNC, CACHEDCLOCK), //
+ // s("perf3PlainNoLoc.xml", LOG20, "All async no loc SysClock",
+ // ALL_ASYNC, SYSCLOCK), //
+ // s("perf5AsyncApndNoLoc.xml", LOG20,
+ // "Async Appender no location"),
+ //
+ // s("perf6AsyncApndLoc.xml", "Async Appender with location"), //
+ // s("perf7MixedNoLoc.xml", "Mixed async no location"), //
+ // s("perf8MixedLoc.xml", "Mixed async with location"), //
+ // s("perf4PlainLocation.xml", "All async with location SysClock",
+ // ALL_ASYNC), //
+ // s("perf4PlainLocation.xml",
+ // "All async with location CachedClock", ALL_ASYNC,
+ // CACHEDCLOCK), //
+ // s("perf4PlainLocation.xml", "All sync with location"), //
+ // s("perf1syncFile.xml", "FileAppender"), //
+ // s("perf1syncFastFile.xml", "FastFileAppender"), //
+ // s("perf2syncRollFile.xml", "RollFileAppender"), //
+ // s("perf2syncRollFastFile.xml", "RollFastFileAppender"), //
+ // };
+
+ String java = args.length > 0 ? args[0] : "java";
+ int repeat = args.length > 1 ? Integer.parseInt(args[1]) : 5;
+ int x = 0;
+ for (Setup config : tests) {
+ System.out.print(config.description());
+ ProcessBuilder pb = config.throughputTest(java);
+ pb.redirectErrorStream(true); // merge System.out and System.err
+ long t1 = System.nanoTime();
+ // int count = config._threadCount >= 16 ? 2 : repeat;
+ int count = repeat;
+ runPerfTest(count, x++, config, pb);
+ System.out.printf(" took %.1f seconds%n", (System.nanoTime() - t1)
+ / (1000.0 * 1000.0 * 1000.0));
+
+ FileReader reader = new FileReader(config._temp);
+ CharBuffer buffer = CharBuffer.allocate(256 * 1024);
+ reader.read(buffer);
+ reader.close();
+ config._temp.delete();
+ buffer.flip();
+
+ String raw = buffer.toString();
+ System.out.print(raw);
+ Stats stats = new Stats(raw, repeat);
+ System.out.println(stats);
+ System.out.println("-----");
+ config._stats = stats;
+ }
+ new File("perftest.log").delete();
+ System.out
+ .printf("Done. Total duration: %.1f minutes%n",
+ (System.nanoTime() - start)
+ / (60.0 * 1000.0 * 1000.0 * 1000.0));
+
+ printRanking((Setup[]) tests.toArray(new Setup[tests.size()]));
+ }
+
+ private static void printRanking(Setup[] tests) {
+ System.out.println();
+ System.out.println("Ranking:");
+ Arrays.sort(tests);
+ for (int i = 0; i < tests.length; i++) {
+ Setup setup = tests[i];
+ System.out.println((i + 1) + ". " + setup.description() + ": "
+ + setup._stats);
+ }
+ }
+
+ private static void runPerfTest(int repeat, int setupIndex, Setup config,
+ ProcessBuilder pb) throws IOException, InterruptedException {
+ for (int i = 0; i < repeat; i++) {
+ System.out.print(" (" + (i + 1) + "/" + repeat + ")...");
+ final Process process = pb.start();
+
+ final boolean[] stop = { false };
+ printProcessOutput(process, stop);
+ process.waitFor();
+ stop[0] = true;
+
+ File gc = new File("gc" + setupIndex + "_" + i
+ + config._log4jConfig + ".log");
+ if (gc.exists()) {
+ gc.delete();
+ }
+ new File("gc.log").renameTo(gc);
+ }
+ }
+
+ private static Thread printProcessOutput(final Process process,
+ final boolean[] stop) {
+
+ Thread t = new Thread("OutputWriter") {
+ public void run() {
+ BufferedReader in = new BufferedReader(new InputStreamReader(
+ process.getInputStream()));
+ try {
+ String line = null;
+ while (!stop[0] && (line = in.readLine()) != null) {
+ System.out.println(line);
+ }
+ } catch (Exception ignored) {
+ }
+ }
+ };
+ t.start();
+ return t;
+ }
+}
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/PerfTestResultFormatter.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/PerfTestResultFormatter.java?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/PerfTestResultFormatter.java (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/PerfTestResultFormatter.java Mon Apr 1 03:51:21 2013
@@ -0,0 +1,167 @@
+package org.apache.logging.log4j.async.perftest;
+
+import java.io.BufferedReader;
+import java.io.InputStreamReader;
+import java.text.DecimalFormat;
+import java.text.NumberFormat;
+import java.text.ParseException;
+import java.util.Arrays;
+import java.util.Comparator;
+import java.util.List;
+import java.util.Map;
+import java.util.Set;
+import java.util.TreeMap;
+
+/**
+ * Utility class that can read the "Ranking" output of the PerfTestDriver and
+ * format it for pasting into Excel.
+ */
+class PerfTestResultFormatter {
+ static final String LF = System.getProperty("line.separator");
+ static final NumberFormat NUM = new DecimalFormat("#,##0");
+
+ static class Stats {
+ long throughput;
+ double avgLatency;
+ double latency99Pct;
+ double latency99_99Pct;
+
+ Stats(String throughput, String avg, String lat99, String lat99_99)
+ throws ParseException {
+ this.throughput = NUM.parse(throughput.trim()).longValue();
+ this.avgLatency = Double.parseDouble(avg.trim());
+ this.latency99Pct = Double.parseDouble(lat99.trim());
+ this.latency99_99Pct = Double.parseDouble(lat99_99.trim());
+ }
+ }
+
+ private Map<String, Map<String, Stats>> results = new TreeMap<String, Map<String, Stats>>();
+
+ public PerfTestResultFormatter() {
+ }
+
+ public String format(String text) throws ParseException {
+ results.clear();
+ String[] lines = text.split("[\\r\\n]+");
+ for (String line : lines) {
+ process(line);
+ }
+ return latencyTable() + LF + throughputTable();
+ }
+
+ private String latencyTable() {
+ StringBuilder sb = new StringBuilder(4 * 1024);
+ Set<String> subKeys = results.values().iterator().next().keySet();
+ char[] tabs = new char[subKeys.size()];
+ Arrays.fill(tabs, '\t');
+ String sep = new String(tabs);
+ sb.append("\tAverage latency" + sep + "99% less than" + sep
+ + "99.99% less than");
+ sb.append(LF);
+ for (int i = 0; i < 3; i++) {
+ for (String subKey : subKeys) {
+ sb.append("\t").append(subKey);
+ }
+ }
+ sb.append(LF);
+ for (String key : results.keySet()) {
+ sb.append(key);
+ for (int i = 0; i < 3; i++) {
+ Map<String, Stats> sub = results.get(key);
+ for (String subKey : sub.keySet()) {
+ Stats stats = sub.get(subKey);
+ switch (i) {
+ case 0:
+ sb.append("\t").append((long) stats.avgLatency);
+ break;
+ case 1:
+ sb.append("\t").append((long) stats.latency99Pct);
+ break;
+ case 2:
+ sb.append("\t").append((long) stats.latency99_99Pct);
+ break;
+ }
+ }
+ }
+ sb.append(LF);
+ }
+ return sb.toString();
+ }
+
+ private String throughputTable() {
+ StringBuilder sb = new StringBuilder(4 * 1024);
+ Set<String> subKeys = results.values().iterator().next().keySet();
+ sb.append("\tThroughput per thread (msg/sec)");
+ sb.append(LF);
+ for (String subKey : subKeys) {
+ sb.append("\t").append(subKey);
+ }
+ sb.append(LF);
+ for (String key : results.keySet()) {
+ sb.append(key);
+ Map<String, Stats> sub = results.get(key);
+ for (String subKey : sub.keySet()) {
+ Stats stats = sub.get(subKey);
+ sb.append("\t").append((long) stats.throughput);
+ }
+ sb.append(LF);
+ }
+ return sb.toString();
+ }
+
+ private void process(String line) throws ParseException {
+ String key = line.substring(line.indexOf('.') + 1, line.indexOf('('));
+ String sub = line.substring(line.indexOf('(') + 1, line.indexOf(')'));
+ String throughput = line.substring(line.indexOf("throughput: ")
+ + "throughput: ".length(), line.indexOf(" ops"));
+ String avg = line.substring(line.indexOf("avg=") + "avg=".length(),
+ line.indexOf(" 99%"));
+ String pct99 = line.substring(
+ line.indexOf("99% < ") + "99% < ".length(),
+ line.indexOf(" 99.99%"));
+ String pct99_99 = line.substring(line.indexOf("99.99% < ")
+ + "99.99% < ".length(), line.lastIndexOf('(') - 1);
+ Stats stats = new Stats(throughput, avg, pct99, pct99_99);
+ Map<String, Stats> map = results.get(key.trim());
+ if (map == null) {
+ map = new TreeMap<String, Stats>(sort());
+ results.put(key.trim(), map);
+ }
+ String subKey = sub.trim();
+ if ("single thread".equals(subKey)) {
+ subKey = "1 thread";
+ }
+ map.put(subKey, stats);
+ }
+
+ private Comparator<String> sort() {
+ return new Comparator<String>() {
+ List<String> expected = Arrays.asList("1 thread", "2 threads",
+ "4 threads", "8 threads", "16 threads", "32 threads",
+ "64 threads");
+
+ @Override
+ public int compare(String o1, String o2) {
+ int i1 = expected.indexOf(o1);
+ int i2 = expected.indexOf(o2);
+ if (i1 < 0 || i2 < 0) {
+ return o1.compareTo(o2);
+ }
+ return i1 - i2;
+ }
+ };
+ }
+
+ public static void main(String[] args) throws Exception {
+ PerfTestResultFormatter fmt = new PerfTestResultFormatter();
+ BufferedReader reader = new BufferedReader(new InputStreamReader(
+ System.in));
+ String line = null;
+ while ((line = reader.readLine()) != null) {
+ fmt.process(line);
+ }
+ System.out.println(fmt.latencyTable());
+ System.out.println();
+ System.out.println(fmt.throughputTable());
+ }
+}
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/RunLog4j1.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/RunLog4j1.java?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/RunLog4j1.java (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/RunLog4j1.java Mon Apr 1 03:51:21 2013
@@ -0,0 +1,53 @@
+package org.apache.logging.log4j.async.perftest;
+
+import org.apache.log4j.LogManager;
+import org.apache.log4j.Logger;
+
+import com.lmax.disruptor.collections.Histogram;
+
+public class RunLog4j1 implements IPerfTestRunner {
+
+ @Override
+ public void runThroughputTest(int lines, Histogram histogram) {
+ long s1 = System.nanoTime();
+ Logger logger = LogManager.getLogger(getClass());
+ for (int j = 0; j < lines; j++) {
+ logger.info(THROUGHPUT_MSG);
+ }
+ long s2 = System.nanoTime();
+ long opsPerSec = (1000L * 1000L * 1000L * lines) / (s2 - s1);
+ histogram.addObservation(opsPerSec);
+ }
+
+ @Override
+ public void runLatencyTest(int samples, Histogram histogram,
+ long nanoTimeCost, int threadCount) {
+ Logger logger = LogManager.getLogger(getClass());
+ for (int i = 0; i < samples; i++) {
+ long s1 = System.nanoTime();
+ logger.info(LATENCY_MSG);
+ long s2 = System.nanoTime();
+ long value = s2 - s1 - nanoTimeCost;
+ if (value > 0) {
+ histogram.addObservation(value);
+ }
+ // wait 1 microsec
+ final long PAUSE_NANOS = 10000 * threadCount;
+ long pauseStart = System.nanoTime();
+ while (PAUSE_NANOS > (System.nanoTime() - pauseStart)) {
+ // busy spin
+ }
+ }
+ }
+
+ @Override
+ public void shutdown() {
+ LogManager.shutdown();
+ }
+
+ @Override
+ public void log(String finalMessage) {
+ Logger logger = LogManager.getLogger(getClass());
+ logger.info(finalMessage);
+ }
+}
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/RunLog4j2.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/RunLog4j2.java?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/RunLog4j2.java (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/RunLog4j2.java Mon Apr 1 03:51:21 2013
@@ -0,0 +1,57 @@
+package org.apache.logging.log4j.async.perftest;
+
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.core.LifeCycle;
+
+import com.lmax.disruptor.collections.Histogram;
+
+public class RunLog4j2 implements IPerfTestRunner {
+
+ @Override
+ public void runThroughputTest(int lines, Histogram histogram) {
+ long s1 = System.nanoTime();
+ Logger logger = LogManager.getLogger(getClass());
+ for (int j = 0; j < lines; j++) {
+ logger.info(THROUGHPUT_MSG);
+ }
+ long s2 = System.nanoTime();
+ long opsPerSec = (1000L * 1000L * 1000L * lines) / (s2 - s1);
+ histogram.addObservation(opsPerSec);
+ }
+
+
+ @Override
+ public void runLatencyTest(int samples, Histogram histogram,
+ long nanoTimeCost, int threadCount) {
+ Logger logger = LogManager.getLogger(getClass());
+ for (int i = 0; i < samples; i++) {
+ long s1 = System.nanoTime();
+ logger.info(LATENCY_MSG);
+ long s2 = System.nanoTime();
+ long value = s2 - s1 - nanoTimeCost;
+ if (value > 0) {
+ histogram.addObservation(value);
+ }
+ // wait 1 microsec
+ final long PAUSE_NANOS = 10000 * threadCount;
+ long pauseStart = System.nanoTime();
+ while (PAUSE_NANOS > (System.nanoTime() - pauseStart)) {
+ // busy spin
+ }
+ }
+ }
+
+
+ @Override
+ public void shutdown() {
+ ((LifeCycle) LogManager.getContext()).stop(); // stop async thread
+ }
+
+
+ @Override
+ public void log(String finalMessage) {
+ Logger logger = LogManager.getLogger(getClass());
+ logger.info(finalMessage);
+ }
+}
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/RunLogback.java
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/RunLogback.java?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/RunLogback.java (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/java/org/apache/logging/log4j/async/perftest/RunLogback.java Mon Apr 1 03:51:21 2013
@@ -0,0 +1,55 @@
+package org.apache.logging.log4j.async.perftest;
+
+import org.slf4j.LoggerFactory;
+
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.core.spi.LifeCycle;
+
+import com.lmax.disruptor.collections.Histogram;
+
+public class RunLogback implements IPerfTestRunner {
+
+ @Override
+ public void runThroughputTest(int lines, Histogram histogram) {
+ long s1 = System.nanoTime();
+ Logger logger = (Logger) LoggerFactory.getLogger(getClass());
+ for (int j = 0; j < lines; j++) {
+ logger.info(THROUGHPUT_MSG);
+ }
+ long s2 = System.nanoTime();
+ long opsPerSec = (1000L * 1000L * 1000L * lines) / (s2 - s1);
+ histogram.addObservation(opsPerSec);
+ }
+
+ @Override
+ public void runLatencyTest(int samples, Histogram histogram,
+ long nanoTimeCost, int threadCount) {
+ Logger logger = (Logger) LoggerFactory.getLogger(getClass());
+ for (int i = 0; i < samples; i++) {
+ long s1 = System.nanoTime();
+ logger.info(LATENCY_MSG);
+ long s2 = System.nanoTime();
+ long value = s2 - s1 - nanoTimeCost;
+ if (value > 0) {
+ histogram.addObservation(value);
+ }
+ // wait 1 microsec
+ final long PAUSE_NANOS = 10000 * threadCount;
+ long pauseStart = System.nanoTime();
+ while (PAUSE_NANOS > (System.nanoTime() - pauseStart)) {
+ // busy spin
+ }
+ }
+ }
+
+ @Override
+ public void shutdown() {
+ ((LifeCycle) LoggerFactory.getILoggerFactory()).stop();
+ }
+
+ @Override
+ public void log(String msg) {
+ Logger logger = (Logger) LoggerFactory.getLogger(getClass());
+ logger.info(msg);
+ }
+}
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/AsyncLoggerConfigTest.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/AsyncLoggerConfigTest.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/AsyncLoggerConfigTest.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/AsyncLoggerConfigTest.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,19 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <File name="File" fileName="AsyncLoggerConfigTest.log" bufferedIO="false" immediateFlush="true" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %m %location %ex%n</pattern>
+ </PatternLayout>
+ </File>
+ </appenders>
+
+ <loggers>
+ <asyncLogger name="com.foo.Bar" level="trace" includeLocation="false">
+ <appender-ref ref="File"/>
+ </asyncLogger>
+ <root level="info">
+ <appender-ref ref="File"/>
+ </root>
+ </loggers>
+</configuration>
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/AsyncLoggerLocationTest.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/AsyncLoggerLocationTest.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/AsyncLoggerLocationTest.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/AsyncLoggerLocationTest.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,17 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastFile name="FastFile" fileName="AsyncLoggerLocationTest.log"
+ immediateFlush="false" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %location %m %ex%n</pattern>
+ </PatternLayout>
+ </FastFile>
+ </appenders>
+
+ <loggers>
+ <root level="info" includeLocation="true">
+ <appender-ref ref="FastFile"/>
+ </root>
+ </loggers>
+</configuration>
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/AsyncLoggerTest.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/AsyncLoggerTest.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/AsyncLoggerTest.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/AsyncLoggerTest.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,17 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastFile name="FastFile" fileName="AsyncLoggerTest.log"
+ immediateFlush="false" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %location %m %ex%n</pattern>
+ </PatternLayout>
+ </FastFile>
+ </appenders>
+
+ <loggers>
+ <root level="info" includeLocation="false">
+ <appender-ref ref="FastFile"/>
+ </root>
+ </loggers>
+</configuration>
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastFileAppenderLocationTest.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastFileAppenderLocationTest.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastFileAppenderLocationTest.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastFileAppenderLocationTest.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,19 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastFile name="FastFile" fileName="FastFileAppenderLocationTest.log" immediateFlush="false" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %m %location %ex%n</pattern>
+ <!--
+ <pattern>%d %p %c{1.} %C %location %line [%t] %X{aKey} %m %ex%n</pattern>
+ -->
+ </PatternLayout>
+ </FastFile>
+ </appenders>
+
+ <loggers>
+ <asyncRoot level="info" includeLocation="true">
+ <appender-ref ref="FastFile"/>
+ </asyncRoot>
+ </loggers>
+</configuration>
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastFileAppenderTest.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastFileAppenderTest.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastFileAppenderTest.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastFileAppenderTest.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,19 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastFile name="FastFile" fileName="FastFileAppenderTest.log" immediateFlush="false" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %m %location %ex%n</pattern>
+ <!--
+ <pattern>%d %p %c{1.} %C %location %line [%t] %X{aKey} %m %ex%n</pattern>
+ -->
+ </PatternLayout>
+ </FastFile>
+ </appenders>
+
+ <loggers>
+ <asyncRoot level="info" includeLocation="false">
+ <appender-ref ref="FastFile"/>
+ </asyncRoot>
+ </loggers>
+</configuration>
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastRollingFileAppenderLocationTest.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastRollingFileAppenderLocationTest.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastRollingFileAppenderLocationTest.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastRollingFileAppenderLocationTest.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,21 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastRollingFile name="FastRollingFile" fileName="FastRollingFileAppenderLocationTest.log"
+ filePattern="test-%d{MM-dd-yyyy}-%i.log.gz" append="false"
+ immediateFlush="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %m %location %ex%n</pattern>
+ </PatternLayout>
+ <Policies>
+ <TimeBasedTriggeringPolicy />
+ </Policies>
+ </FastRollingFile>
+ </appenders>
+
+ <loggers>
+ <asyncRoot level="info" includeLocation="true">
+ <appender-ref ref="FastRollingFile"/>
+ </asyncRoot>
+ </loggers>
+</configuration>
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastRollingFileAppenderTest.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastRollingFileAppenderTest.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastRollingFileAppenderTest.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/FastRollingFileAppenderTest.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,21 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastRollingFile name="FastRollingFile" fileName="FastRollingFileAppenderTest.log"
+ filePattern="test-%d{MM-dd-yyyy}-%i.log.gz" append="false"
+ immediateFlush="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %m %location %ex%n</pattern>
+ </PatternLayout>
+ <Policies>
+ <TimeBasedTriggeringPolicy />
+ </Policies>
+ </FastRollingFile>
+ </appenders>
+
+ <loggers>
+ <asyncRoot level="info" includeLocation="false">
+ <appender-ref ref="FastRollingFile"/>
+ </asyncRoot>
+ </loggers>
+</configuration>
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/log4j.dtd
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/log4j.dtd?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/log4j.dtd (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/log4j.dtd Mon Apr 1 03:51:21 2013
@@ -0,0 +1,170 @@
+<?xml version="1.0" encoding="UTF-8" ?>
+
+<!-- log4j-1.2.dtd is included in the log4perl distribution
+for your convenience. The log4perl dtd is based on this
+version of the log4j.dtd -->
+
+<!-- Authors: Chris Taylor, Ceki Gulcu. -->
+
+<!-- Version: 1.2 -->
+
+<!-- A configuration element consists of optional renderer
+elements,appender elements, categories and an optional root
+element. -->
+
+<!ELEMENT log4j:configuration (renderer*, appender*,(category|logger)*,root?,
+ categoryFactory?)>
+
+<!-- The "threshold" attribute takes a level value such that all -->
+<!-- logging statements with a level equal or below this value are -->
+<!-- disabled. -->
+
+<!-- Setting the "debug" enable the printing of internal log4j logging -->
+<!-- statements. -->
+
+<!-- By default, debug attribute is "null", meaning that we not do touch -->
+<!-- internal log4j logging settings. The "null" value for the threshold -->
+<!-- attribute can be misleading. The threshold field of a repository -->
+<!-- cannot be set to null. The "null" value for the threshold attribute -->
+<!-- simply means don't touch the threshold field, the threshold field -->
+<!-- keeps its old value. -->
+
+<!ATTLIST log4j:configuration
+ xmlns:log4j CDATA #FIXED "http://jakarta.apache.org/log4j/"
+ threshold (all|debug|info|warn|error|fatal|off|null) "null"
+ debug (true|false|null) "null"
+>
+
+<!-- renderer elements allow the user to customize the conversion of -->
+<!-- message objects to String. -->
+
+<!ELEMENT renderer EMPTY>
+<!ATTLIST renderer
+ renderedClass CDATA #REQUIRED
+ renderingClass CDATA #REQUIRED
+>
+
+<!-- Appenders must have a name and a class. -->
+<!-- Appenders may contain an error handler, a layout, optional parameters -->
+<!-- and filters. They may also reference (or include) other appenders. -->
+<!ELEMENT appender (errorHandler?, param*, layout?, filter*, appender-ref*)>
+<!ATTLIST appender
+ name ID #REQUIRED
+ class CDATA #REQUIRED
+>
+
+<!ELEMENT layout (param*)>
+<!ATTLIST layout
+ class CDATA #REQUIRED
+>
+
+<!ELEMENT filter (param*)>
+<!ATTLIST filter
+ class CDATA #REQUIRED
+>
+
+<!-- ErrorHandlers can be of any class. They can admit any number of -->
+<!-- parameters. -->
+
+<!ELEMENT errorHandler (param*, root-ref?, logger-ref*, appender-ref?)>
+<!ATTLIST errorHandler
+ class CDATA #REQUIRED
+>
+
+<!ELEMENT root-ref EMPTY>
+
+<!ELEMENT logger-ref EMPTY>
+<!ATTLIST logger-ref
+ ref IDREF #REQUIRED
+>
+
+<!ELEMENT param EMPTY>
+<!ATTLIST param
+ name CDATA #REQUIRED
+ value CDATA #REQUIRED
+>
+
+
+<!-- The priority class is org.apache.log4j.Level by default -->
+<!ELEMENT priority (param*)>
+<!ATTLIST priority
+ class CDATA #IMPLIED
+ value CDATA #REQUIRED
+>
+
+<!-- The level class is org.apache.log4j.Level by default -->
+<!ELEMENT level (param*)>
+<!ATTLIST level
+ class CDATA #IMPLIED
+ value CDATA #REQUIRED
+>
+
+
+<!-- If no level element is specified, then the configurator MUST not -->
+<!-- touch the level of the named category. -->
+<!ELEMENT category (param*,(priority|level)?,appender-ref*)>
+<!ATTLIST category
+ class CDATA #IMPLIED
+ name CDATA #REQUIRED
+ additivity (true|false) "true"
+>
+
+<!-- If no level element is specified, then the configurator MUST not -->
+<!-- touch the level of the named logger. -->
+<!ELEMENT logger (level?,appender-ref*)>
+<!ATTLIST logger
+ name ID #REQUIRED
+ additivity (true|false) "true"
+>
+
+
+<!ELEMENT categoryFactory (param*)>
+<!ATTLIST categoryFactory
+ class CDATA #REQUIRED>
+
+<!ELEMENT appender-ref EMPTY>
+<!ATTLIST appender-ref
+ ref IDREF #REQUIRED
+>
+
+<!-- If no priority element is specified, then the configurator MUST not -->
+<!-- touch the priority of root. -->
+<!-- The root category always exists and cannot be subclassed. -->
+<!ELEMENT root (param*, (priority|level)?, appender-ref*)>
+
+
+<!-- ==================================================================== -->
+<!-- A logging event -->
+<!-- ==================================================================== -->
+<!ELEMENT log4j:eventSet (log4j:event*)>
+<!ATTLIST log4j:eventSet
+ xmlns:log4j CDATA #FIXED "http://jakarta.apache.org/log4j/"
+ version (1.1|1.2) "1.2"
+ includesLocationInfo (true|false) "true"
+>
+
+
+
+<!ELEMENT log4j:event (log4j:message, log4j:NDC?, log4j:throwable?,
+ log4j:locationInfo?) >
+
+<!-- The timestamp format is application dependent. -->
+<!ATTLIST log4j:event
+ logger CDATA #REQUIRED
+ level CDATA #REQUIRED
+ thread CDATA #REQUIRED
+ timestamp CDATA #REQUIRED
+>
+
+<!ELEMENT log4j:message (#PCDATA)>
+<!ELEMENT log4j:NDC (#PCDATA)>
+
+<!ELEMENT log4j:throwable (#PCDATA)>
+
+<!ELEMENT log4j:locationInfo EMPTY>
+<!ATTLIST log4j:locationInfo
+ class CDATA #REQUIRED
+ method CDATA #REQUIRED
+ file CDATA #REQUIRED
+ line CDATA #REQUIRED
+>
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-log4j12-async.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-log4j12-async.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-log4j12-async.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-log4j12-async.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,20 @@
+<?xml version="1.0" encoding="UTF-8" ?>
+<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
+<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
+ <appender name="File" class="org.apache.log4j.FileAppender">
+ <param name="File" value="perftest.log" />
+ <param name="BufferedIO" value="true"/>
+ <param name="Append" value="false" />
+ <layout class="org.apache.log4j.PatternLayout">
+ <param name="ConversionPattern" value="%d %p %c{1} [%t] %X{aKey} %m %n"/>
+ </layout>
+ </appender>
+ <appender name="ASYNC" class="org.apache.log4j.AsyncAppender">
+ <param name="BufferSize" value="262144"/>
+ <appender-ref ref="File"/>
+ </appender>
+ <root>
+ <priority value="debug" />
+ <appender-ref ref="ASYNC" />
+ </root>
+</log4j:configuration>
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-log4j12.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-log4j12.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-log4j12.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-log4j12.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,16 @@
+<?xml version="1.0" encoding="UTF-8" ?>
+<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
+<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
+ <appender name="File" class="org.apache.log4j.FileAppender">
+ <param name="File" value="perftest.log" />
+ <param name="BufferedIO" value="true"/>
+ <param name="Append" value="false" />
+ <layout class="org.apache.log4j.PatternLayout">
+ <param name="ConversionPattern" value="%d %p %c{1} [%t] %X{aKey} %m %n"/>
+ </layout>
+ </appender>
+ <root>
+ <priority value="debug" />
+ <appender-ref ref="File" />
+ </root>
+</log4j:configuration>
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-logback-async.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-logback-async.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-logback-async.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-logback-async.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,21 @@
+<configuration>
+
+ <appender name="FILE" class="ch.qos.logback.core.FileAppender">
+ <file>perftest.log</file>
+ <append>false</append>
+ <encoder>
+ <pattern>%d %p %c{1} [%t] %X{aKey} %m %ex%n</pattern>
+ <immediateFlush>false</immediateFlush>
+ </encoder>
+ </appender>
+ <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
+ <queueSize>262144</queueSize>
+ <discardingThreshold>0</discardingThreshold>
+ <includeCallerData>false</includeCallerData>
+ <appender-ref ref="FILE" />
+ </appender>
+
+ <root level="debug">
+ <appender-ref ref="ASYNC" />
+ </root>
+</configuration>
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-logback.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-logback.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-logback.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf-logback.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,15 @@
+<configuration>
+
+ <appender name="FILE" class="ch.qos.logback.core.FileAppender">
+ <file>perftest.log</file>
+ <append>false</append>
+ <encoder>
+ <pattern>%d %p %c{1} [%t] %X{aKey} %m %ex%n</pattern>
+ <immediateFlush>false</immediateFlush>
+ </encoder>
+ </appender>
+
+ <root level="debug">
+ <appender-ref ref="FILE" />
+ </root>
+</configuration>
\ No newline at end of file
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf1syncFastFile.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf1syncFastFile.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf1syncFastFile.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf1syncFastFile.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,15 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastFile name="FastFile" fileName="perftest.log" immediateFlush="false" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %m %ex%n</pattern>
+ </PatternLayout>
+ </FastFile>
+ </appenders>
+ <loggers>
+ <root level="info" includeLocation="false">
+ <appender-ref ref="FastFile"/>
+ </root>
+ </loggers>
+</configuration>
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf1syncFile.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf1syncFile.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf1syncFile.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf1syncFile.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,15 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <File name="File" fileName="perftest.log" bufferedIO="true" immediateFlush="false" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %m %ex%n</pattern>
+ </PatternLayout>
+ </File>
+ </appenders>
+ <loggers>
+ <root level="info" includeLocation="false">
+ <appender-ref ref="File"/>
+ </root>
+ </loggers>
+</configuration>
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf2syncRollFastFile.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf2syncRollFastFile.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf2syncRollFastFile.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf2syncRollFastFile.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,20 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastRollingFile name="FastRollingFile" fileName="perftest.log"
+ filePattern="app-%d{MM-dd-yyyy}-%i.log.gz" append="false"
+ immediateFlush="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %m %ex%n</pattern>
+ </PatternLayout>
+ <Policies>
+ <TimeBasedTriggeringPolicy />
+ </Policies>
+ </FastRollingFile>
+ </appenders>
+ <loggers>
+ <root level="info" includeLocation="false">
+ <appender-ref ref="FastRollingFile"/>
+ </root>
+ </loggers>
+</configuration>
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf2syncRollFile.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf2syncRollFile.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf2syncRollFile.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf2syncRollFile.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,20 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <RollingFile name="RollingFile" fileName="perftest.log"
+ filePattern="app-%d{MM-dd-yyyy}-%i.log.gz" append="false"
+ bufferedIO="true" immediateFlush="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %m %ex%n</pattern>
+ </PatternLayout>
+ <Policies>
+ <TimeBasedTriggeringPolicy />
+ </Policies>
+ </RollingFile>
+ </appenders>
+ <loggers>
+ <root level="info" includeLocation="false">
+ <appender-ref ref="RollingFile"/>
+ </root>
+ </loggers>
+</configuration>
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf3PlainNoLoc.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf3PlainNoLoc.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf3PlainNoLoc.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf3PlainNoLoc.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,15 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastFile name="FastFile" fileName="perftest.log" immediateFlush="false" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %m %ex%n</pattern>
+ </PatternLayout>
+ </FastFile>
+ </appenders>
+ <loggers>
+ <root level="info" includeLocation="false">
+ <appender-ref ref="FastFile"/>
+ </root>
+ </loggers>
+</configuration>
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf4PlainLocation.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf4PlainLocation.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf4PlainLocation.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf4PlainLocation.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,15 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastFile name="FastFile" fileName="perftest.log" immediateFlush="false" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} %C %location %line [%t] %X{aKey} %m %ex%n</pattern>
+ </PatternLayout>
+ </FastFile>
+ </appenders>
+ <loggers>
+ <root level="info" includeLocation="true">
+ <appender-ref ref="FastFile"/>
+ </root>
+ </loggers>
+</configuration>
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf5AsyncApndNoLoc.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf5AsyncApndNoLoc.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf5AsyncApndNoLoc.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf5AsyncApndNoLoc.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,18 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastFile name="FastFile" fileName="perftest.log" immediateFlush="false" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %m %ex%n</pattern>
+ </PatternLayout>
+ </FastFile>
+ <Asynch name="Asynch" blocking="true" bufferSize="262144">
+ <appender-ref ref="FastFile"/>
+ </Asynch>
+ </appenders>
+ <loggers>
+ <root level="info" includeLocation="false">
+ <appender-ref ref="Asynch"/>
+ </root>
+ </loggers>
+</configuration>
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf6AsyncApndLoc.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf6AsyncApndLoc.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf6AsyncApndLoc.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf6AsyncApndLoc.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,18 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastFile name="FastFile" fileName="perftest.log" immediateFlush="false" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} %C %location %line [%t] %X{aKey} %m %ex%n</pattern>
+ </PatternLayout>
+ </FastFile>
+ <Asynch name="Asynch" includeLocation="true" blocking="true" bufferSize="262144">
+ <appender-ref ref="FastFile"/>
+ </Asynch>
+ </appenders>
+ <loggers>
+ <root level="info" includeLocation="true">
+ <appender-ref ref="Asynch"/>
+ </root>
+ </loggers>
+</configuration>
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf7MixedNoLoc.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf7MixedNoLoc.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf7MixedNoLoc.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf7MixedNoLoc.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,15 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastFile name="FastFile" fileName="perftest.log" immediateFlush="false" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} [%t] %X{aKey} %m %ex%n</pattern>
+ </PatternLayout>
+ </FastFile>
+ </appenders>
+ <loggers>
+ <asyncRoot level="info" includeLocation="false">
+ <appender-ref ref="FastFile"/>
+ </asyncRoot>
+ </loggers>
+</configuration>
Added: logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf8MixedLoc.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf8MixedLoc.xml?rev=1463078&view=auto
==============================================================================
--- logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf8MixedLoc.xml (added)
+++ logging/log4j/log4j2/trunk/log4j-async/src/test/resources/perf8MixedLoc.xml Mon Apr 1 03:51:21 2013
@@ -0,0 +1,15 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<configuration status="OFF">
+ <appenders>
+ <FastFile name="FastFile" fileName="perftest.log" immediateFlush="false" append="false">
+ <PatternLayout>
+ <pattern>%d %p %c{1.} %C %location %line [%t] %X{aKey} %m %ex%n</pattern>
+ </PatternLayout>
+ </FastFile>
+ </appenders>
+ <loggers>
+ <asyncRoot level="info" includeLocation="true">
+ <appender-ref ref="FastFile"/>
+ </asyncRoot>
+ </loggers>
+</configuration>
\ No newline at end of file
Modified: logging/log4j/log4j2/trunk/pom.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/pom.xml?rev=1463078&r1=1463077&r2=1463078&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/pom.xml (original)
+++ logging/log4j/log4j2/trunk/pom.xml Mon Apr 1 03:51:21 2013
@@ -115,8 +115,8 @@
<javadoc.plugin.version>2.9</javadoc.plugin.version>
<surefire.plugin.version>2.12.4</surefire.plugin.version>
<manifestfile>target/osgi/MANIFEST.MF</manifestfile>
- <maven.compile.source>1.5</maven.compile.source>
- <maven.compile.target>1.5</maven.compile.target>
+ <maven.compile.source>1.6</maven.compile.source>
+ <maven.compile.target>1.6</maven.compile.target>
<docLabel>Site Documentation</docLabel>
<projectDir />
</properties>
@@ -556,6 +556,7 @@
<module>flume-ng</module>
<module>web</module>
<module>samples</module>
+ <module>log4j-async</module>
</modules>
<profiles>
<profile>
Modified: logging/log4j/log4j2/trunk/src/changes/changes.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/changes/changes.xml?rev=1463078&r1=1463077&r2=1463078&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/changes/changes.xml (original)
+++ logging/log4j/log4j2/trunk/src/changes/changes.xml Mon Apr 1 03:51:21 2013
@@ -23,6 +23,21 @@
<body>
<release version="2.0-beta5" date="@TBD@" description="Bug fixes and enhancements">
+ <action issue="LOG4J2-157" dev="rgoers" type="update" due-to="Remko Popma">
+ Allowed Loggers access to the properties in the LoggerConfig.
+ </action>
+ <action issue="LOG4J2-153" dev="rgoers" type="update" due-to="Remko Popma">
+ Added ability to include or exclude location information.
+ </action>
+ <action issue="LOG4J2-151" dev="rgoers" type="update" due-to="Remko Popma">
+ Allow Logger and LoggerContext to be subclassed.
+ </action>
+ <action issue="LOG4J2-164" dev="rgoers" type="add" due-to="Remko Popma">
+ Add methods is/setEndOfBatch to LogEvent.
+ </action>
+ <action issue="LOG4J2-163" dev="rgoers" type="add" due-to="Remko Popma">
+ Add support for asynchronous loggers.
+ </action>
<action issue="LOG4J2-189" dev="rgoers" type="fix" due-to="Werner">
The blocking parameter did not work properly on AsynchAppender.
</action>
Modified: logging/log4j/log4j2/trunk/src/site/site.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/site.xml?rev=1463078&r1=1463077&r2=1463078&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/site.xml (original)
+++ logging/log4j/log4j2/trunk/src/site/site.xml Mon Apr 1 03:51:21 2013
@@ -101,6 +101,17 @@
<item name="Time" href="/manual/filters.html#TimeFilter"/>
</item>
+ <item name="Async" href="/manual/async.html" collapse="true">
+ <item name="Trade-offs" href="/manual/async.html#Trade-offs"/>
+ <item name="All Loggers Async" href="/manual/async.html#AllAsync"/>
+ <item name="Mixed Sync & Async" href="/manual/async.html#MixedSync-Async"/>
+ <item name="Location" href="/manual/async.html#Location"/>
+ <item name="FastFileAppender" href="/manual/async.html#FastFileAppender"/>
+ <item name="FastRollingFileAppender" href="/manual/async.html#FastRollingFileAppender"/>
+ <item name="Performance" href="/manual/async.html#Performance"/>
+ <item name="Under The Hood" href="/manual/async.html#UnderTheHood"/>
+ </item>
+
<item name="JMX" href="/manual/jmx.html"/>
<item name="Logging Separation" href="/manual/logsep.html"/>
@@ -121,6 +132,7 @@
<menu name="Components" inherit="top" img="icon-cog">
<item name="API" href="log4j-api/index.html"/>
<item name="Implementation" href="log4j-core/index.html"/>
+ <item name="Async" href="log4j-async/index.html"/>
<item name="Commons Logging Bridge" href="log4j-jcl/index.html"/>
<item name="Log4J 1.2 API" href="log4j-1.2-api/index.html"/>
<item name="SLF4J Binding" href="log4j-slf4j-impl/index.html"/>
Modified: logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml
URL: http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml?rev=1463078&r1=1463077&r2=1463078&view=diff
==============================================================================
--- logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml (original)
+++ logging/log4j/log4j2/trunk/src/site/xdoc/manual/appenders.xml Mon Apr 1 03:51:21 2013
@@ -67,7 +67,7 @@
<td>blocking</td>
<td>boolean</td>
<td>If true, the appender will wait until there are free slots in the queue. If false, the event
- will be written to the error appender if the queue is full.</td>
+ will be written to the error appender if the queue is full. The default is true.</td>
</tr>
<tr>
<td>bufferSize</td>
@@ -97,6 +97,14 @@
<td>The default is true, causing exceptions to be internally logged and then ignored. When set to
false exceptions will be percolated to the caller.</td>
</tr>
+ <tr>
+ <td>includeLocation</td>
+ <td>boolean</td>
+ <td>Extracting location is an expensive operation (it can make
+ logging 5 - 20 times slower). To improve performance, location is
+ not included by default when adding a log event to the queue.
+ You can change this by setting includeLocation="true".</td>
+ </tr>
<caption align="top">AsynchAppender Parameters</caption>
</table>
<p>