You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by ck...@apache.org on 2018/08/14 14:55:31 UTC
logging-log4j2 git commit: [LOG4J2-2391] Add a
FileAppenderThrowableBenchmark over a more complex stack
Repository: logging-log4j2
Updated Branches:
refs/heads/master c0dee5de7 -> 69f996ac5
[LOG4J2-2391] Add a FileAppenderThrowableBenchmark over a more complex stack
Proxies through several interfaces in order to simulate performance
of a standard application, which doesn't benefit quite as much
from the ThrowableProxy Map<String, CacheEntry> cache.
Initial results:
Benchmark Mode Cnt Score Error Units
FileAppenderThrowableBenchmark.complexLog4j1 thrpt 3 8562.548 ± 4122.961 ops/s
FileAppenderThrowableBenchmark.complexLog4j2ExtendedThrowable thrpt 3 2575.655 ± 218.395 ops/s
FileAppenderThrowableBenchmark.complexLog4j2ExtendedThrowableAsync thrpt 3 2518.260 ± 335.573 ops/s
FileAppenderThrowableBenchmark.complexLog4j2Throwable thrpt 3 12738.874 ± 2867.140 ops/s
FileAppenderThrowableBenchmark.complexLog4j2ThrowableAsync thrpt 3 3489.965 ± 471.234 ops/s
FileAppenderThrowableBenchmark.complexLogbackFile thrpt 3 12866.339 ± 1396.160 ops/s
FileAppenderThrowableBenchmark.julFile thrpt 3 55019.426 ± 9342.755 ops/s
FileAppenderThrowableBenchmark.log4j1 thrpt 3 75444.252 ± 18508.319 ops/s
FileAppenderThrowableBenchmark.log4j2ExtendedThrowable thrpt 3 45708.853 ± 13553.851 ops/s
FileAppenderThrowableBenchmark.log4j2Throwable thrpt 3 110923.511 ± 19661.868 ops/s
FileAppenderThrowableBenchmark.logbackFile thrpt 3 112548.025 ± 40720.422 ops/s
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/69f996ac
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/69f996ac
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/69f996ac
Branch: refs/heads/master
Commit: 69f996ac5190d72e5f7ba84b00a3165309ead399
Parents: c0dee5d
Author: Carter Kozak <ck...@apache.org>
Authored: Thu Aug 9 14:04:16 2018 -0400
Committer: Carter Kozak <ck...@apache.org>
Committed: Tue Aug 14 10:55:21 2018 -0400
----------------------------------------------------------------------
.../jmh/FileAppenderThrowableBenchmark.java | 131 ++++++++++++++++++-
.../resources/log4j2-perf-file-throwable.xml | 6 +
2 files changed, 134 insertions(+), 3 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/69f996ac/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/FileAppenderThrowableBenchmark.java
----------------------------------------------------------------------
diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/FileAppenderThrowableBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/FileAppenderThrowableBenchmark.java
index 6f02c01..7bf5ba9 100644
--- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/FileAppenderThrowableBenchmark.java
+++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/FileAppenderThrowableBenchmark.java
@@ -34,6 +34,10 @@ import org.openjdk.jmh.annotations.Warmup;
import org.slf4j.LoggerFactory;
import java.io.File;
+import java.lang.reflect.InvocationHandler;
+import java.lang.reflect.InvocationTargetException;
+import java.lang.reflect.Method;
+import java.lang.reflect.Proxy;
import java.util.concurrent.TimeUnit;
import java.util.logging.FileHandler;
import java.util.logging.Level;
@@ -51,15 +55,92 @@ import java.util.logging.Level;
@Measurement(iterations = 3, time = 3)
public class FileAppenderThrowableBenchmark {
- private static final Throwable THROWABLE = getThrowable();
+ private static final Throwable THROWABLE = getSimpleThrowable();
+ private static final Throwable COMPLEX_THROWABLE = getComplexThrowable();
- private static Throwable getThrowable() {
+ private static Throwable getSimpleThrowable() {
return new IllegalStateException("Test Throwable");
}
+ interface ThrowableHelper {
+ void action();
+ }
+
+ // Used to create a deeper stack with many different classes
+ // This makes the ThrowableProxy Map<String, CacheEntry> cache
+ // perform more closely to real applications.
+ interface TestIface0 extends ThrowableHelper {}
+ interface TestIface1 extends ThrowableHelper {}
+ interface TestIface2 extends ThrowableHelper {}
+ interface TestIface3 extends ThrowableHelper {}
+ interface TestIface4 extends ThrowableHelper {}
+ interface TestIface5 extends ThrowableHelper {}
+ interface TestIface6 extends ThrowableHelper {}
+ interface TestIface7 extends ThrowableHelper {}
+ interface TestIface8 extends ThrowableHelper {}
+ interface TestIface9 extends ThrowableHelper {}
+ interface TestIface10 extends ThrowableHelper {}
+ interface TestIface11 extends ThrowableHelper {}
+ interface TestIface12 extends ThrowableHelper {}
+ interface TestIface13 extends ThrowableHelper {}
+ interface TestIface14 extends ThrowableHelper {}
+ interface TestIface15 extends ThrowableHelper {}
+ interface TestIface16 extends ThrowableHelper {}
+ interface TestIface17 extends ThrowableHelper {}
+ interface TestIface18 extends ThrowableHelper {}
+ interface TestIface19 extends ThrowableHelper {}
+ interface TestIface20 extends ThrowableHelper {}
+ interface TestIface21 extends ThrowableHelper {}
+ interface TestIface22 extends ThrowableHelper {}
+ interface TestIface23 extends ThrowableHelper {}
+ interface TestIface24 extends ThrowableHelper {}
+ interface TestIface25 extends ThrowableHelper {}
+ interface TestIface26 extends ThrowableHelper {}
+ interface TestIface27 extends ThrowableHelper {}
+ interface TestIface28 extends ThrowableHelper {}
+ interface TestIface29 extends ThrowableHelper {}
+ interface TestIface30 extends ThrowableHelper {}
+
+ private static Throwable getComplexThrowable() {
+ ThrowableHelper helper = new ThrowableHelper() {
+ @Override
+ public void action() {
+ throw new IllegalStateException("Test Throwable");
+ }
+ };
+ try {
+ for (int i = 0; i < 31; i++) {
+ final ThrowableHelper delegate = helper;
+ helper = (ThrowableHelper) Proxy.newProxyInstance(
+ FileAppenderThrowableBenchmark.class.getClassLoader(),
+ new Class<?>[]{Class.forName(FileAppenderThrowableBenchmark.class.getName() + "$TestIface" + (i % 31))},
+ new InvocationHandler() {
+ @Override
+ public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
+ try {
+ return method.invoke(delegate, args);
+ } catch (InvocationTargetException e) {
+ throw e.getCause();
+ }
+ }
+ });
+ }
+ } catch (ClassNotFoundException e) {
+ throw new IllegalStateException("Failed to create stack", e);
+ }
+ try {
+ helper.action();
+ } catch (IllegalStateException e) {
+ return e;
+ }
+ throw new IllegalStateException("Failed to create throwable");
+ }
+
private FileHandler julFileHandler;
Logger log4j2ExtendedThrowable;
+ Logger log4j2ExtendedThrowableAsync;
Logger log4j2SimpleThrowable;
+ Logger log4j2SimpleThrowableAsync;
org.slf4j.Logger slf4jLogger;
org.apache.log4j.Logger log4j1Logger;
java.util.logging.Logger julLogger;
@@ -73,7 +154,9 @@ public class FileAppenderThrowableBenchmark {
System.setProperty("logback.configurationFile", "logback-perf-file-throwable.xml");
log4j2ExtendedThrowable = LogManager.getLogger("RAFExtendedException");
+ log4j2ExtendedThrowableAsync = LogManager.getLogger("async.RAFExtendedException");
log4j2SimpleThrowable = LogManager.getLogger("RAFSimpleException");
+ log4j2SimpleThrowableAsync = LogManager.getLogger("async.RAFSimpleException");
slf4jLogger = LoggerFactory.getLogger(getClass());
log4j1Logger = org.apache.log4j.Logger.getLogger(getClass());
@@ -116,13 +199,34 @@ public class FileAppenderThrowableBenchmark {
@BenchmarkMode(Mode.Throughput)
@OutputTimeUnit(TimeUnit.SECONDS)
@Benchmark
- public void log4j2SimpleThrowable() {
+ public void complexLog4j1() {
+ log4j1Logger.error("Caught an exception", COMPLEX_THROWABLE);
+ }
+
+ @BenchmarkMode(Mode.Throughput)
+ @OutputTimeUnit(TimeUnit.SECONDS)
+ @Benchmark
+ public void log4j2Throwable() {
log4j2SimpleThrowable.error("Caught an exception", THROWABLE);
}
@BenchmarkMode(Mode.Throughput)
@OutputTimeUnit(TimeUnit.SECONDS)
@Benchmark
+ public void complexLog4j2Throwable() {
+ log4j2SimpleThrowable.error("Caught an exception", COMPLEX_THROWABLE);
+ }
+
+ @BenchmarkMode(Mode.Throughput)
+ @OutputTimeUnit(TimeUnit.SECONDS)
+ @Benchmark
+ public void complexLog4j2ThrowableAsync() {
+ log4j2SimpleThrowableAsync.error("Caught an exception", COMPLEX_THROWABLE);
+ }
+
+ @BenchmarkMode(Mode.Throughput)
+ @OutputTimeUnit(TimeUnit.SECONDS)
+ @Benchmark
public void log4j2ExtendedThrowable() {
log4j2ExtendedThrowable.error("Caught an exception", THROWABLE);
}
@@ -130,6 +234,20 @@ public class FileAppenderThrowableBenchmark {
@BenchmarkMode(Mode.Throughput)
@OutputTimeUnit(TimeUnit.SECONDS)
@Benchmark
+ public void complexLog4j2ExtendedThrowable() {
+ log4j2ExtendedThrowable.error("Caught an exception", COMPLEX_THROWABLE);
+ }
+
+ @BenchmarkMode(Mode.Throughput)
+ @OutputTimeUnit(TimeUnit.SECONDS)
+ @Benchmark
+ public void complexLog4j2ExtendedThrowableAsync() {
+ log4j2ExtendedThrowableAsync.error("Caught an exception", COMPLEX_THROWABLE);
+ }
+
+ @BenchmarkMode(Mode.Throughput)
+ @OutputTimeUnit(TimeUnit.SECONDS)
+ @Benchmark
public void logbackFile() {
slf4jLogger.error("Caught an exception", THROWABLE);
}
@@ -137,6 +255,13 @@ public class FileAppenderThrowableBenchmark {
@BenchmarkMode(Mode.Throughput)
@OutputTimeUnit(TimeUnit.SECONDS)
@Benchmark
+ public void complexLogbackFile() {
+ slf4jLogger.error("Caught an exception", COMPLEX_THROWABLE);
+ }
+
+ @BenchmarkMode(Mode.Throughput)
+ @OutputTimeUnit(TimeUnit.SECONDS)
+ @Benchmark
public void julFile() {
// must specify sourceClass or JUL will look it up by walking the stack trace!
julLogger.logp(Level.SEVERE, getClass().getName(), "param1JulFile", "Caught an exception", THROWABLE);
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/69f996ac/log4j-perf/src/main/resources/log4j2-perf-file-throwable.xml
----------------------------------------------------------------------
diff --git a/log4j-perf/src/main/resources/log4j2-perf-file-throwable.xml b/log4j-perf/src/main/resources/log4j2-perf-file-throwable.xml
index 3a4d9a4..fdf3ba5 100644
--- a/log4j-perf/src/main/resources/log4j2-perf-file-throwable.xml
+++ b/log4j-perf/src/main/resources/log4j2-perf-file-throwable.xml
@@ -33,8 +33,14 @@
<Logger name="RAFExtendedException" level="debug" additivity="false">
<AppenderRef ref="RAFExtendedException"/>
</Logger>
+ <Logger name="async.RAFExtendedException" level="debug" additivity="false">
+ <AppenderRef ref="RAFExtendedException"/>
+ </Logger>
<Logger name="RAFSimpleException" level="debug" additivity="false">
<AppenderRef ref="RAFSimpleException"/>
</Logger>
+ <AsyncLogger name="async.RAFSimpleException" level="debug" additivity="false">
+ <AppenderRef ref="RAFSimpleException"/>
+ </AsyncLogger>
</Loggers>
</Configuration>
\ No newline at end of file