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/10/05 21:21:44 UTC

logging-log4j2 git commit: [Do not merge] Stack trace jmh benchmark

Repository: logging-log4j2
Updated Branches:
  refs/heads/ckozak/stack_trace_jmh_benchmark [created] 64bfd3143


[Do not merge] Stack trace jmh benchmark

Should not merge, just for a simple benchmark.
Some code is copied in order to make a direct comparison within
a single jvm configuration.


Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/64bfd314
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/64bfd314
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/64bfd314

Branch: refs/heads/ckozak/stack_trace_jmh_benchmark
Commit: 64bfd31431fa4b9b906b44f95b5dde9e1e1e51d1
Parents: aa3878d
Author: Carter Kozak <ck...@apache.org>
Authored: Wed Aug 8 10:22:52 2018 -0400
Committer: Carter Kozak <ck...@apache.org>
Committed: Fri Oct 5 17:18:59 2018 -0400

----------------------------------------------------------------------
 .../PrivateSecurityManagerStackTraceUtil.java   |   4 +-
 .../log4j/perf/jmh/StackTraceBenchmark.java     | 136 +++++++++++++++++++
 2 files changed, 138 insertions(+), 2 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/64bfd314/log4j-api/src/main/java/org/apache/logging/log4j/util/PrivateSecurityManagerStackTraceUtil.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/util/PrivateSecurityManagerStackTraceUtil.java b/log4j-api/src/main/java/org/apache/logging/log4j/util/PrivateSecurityManagerStackTraceUtil.java
index 51bca15..d91d6f4 100644
--- a/log4j-api/src/main/java/org/apache/logging/log4j/util/PrivateSecurityManagerStackTraceUtil.java
+++ b/log4j-api/src/main/java/org/apache/logging/log4j/util/PrivateSecurityManagerStackTraceUtil.java
@@ -22,7 +22,7 @@ import java.util.Stack;
  * Internal utility to share a fast implementation of {@link #getCurrentStackTrace()}
  * with the java 9 implementation of {@link StackLocator}.
  */
-final class PrivateSecurityManagerStackTraceUtil {
+public final class PrivateSecurityManagerStackTraceUtil {
 
     private static final PrivateSecurityManager SECURITY_MANAGER;
 
@@ -50,7 +50,7 @@ final class PrivateSecurityManagerStackTraceUtil {
     }
 
     // benchmarks show that using the SecurityManager is much faster than looping through getCallerClass(int)
-    static Stack<Class<?>> getCurrentStackTrace() {
+    public static Stack<Class<?>> getCurrentStackTrace() {
         final Class<?>[] array = SECURITY_MANAGER.getClassContext();
         final Stack<Class<?>> classes = new Stack<>();
         classes.ensureCapacity(array.length);

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/64bfd314/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/StackTraceBenchmark.java
----------------------------------------------------------------------
diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/StackTraceBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/StackTraceBenchmark.java
new file mode 100644
index 0000000..ca585c5
--- /dev/null
+++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/StackTraceBenchmark.java
@@ -0,0 +1,136 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache license, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the license for the specific language governing permissions and
+ * limitations under the license.
+ */
+
+package org.apache.logging.log4j.perf.jmh;
+
+import org.apache.logging.log4j.util.LoaderUtil;
+import org.apache.logging.log4j.util.PrivateSecurityManagerStackTraceUtil;
+import org.openjdk.jmh.annotations.Benchmark;
+import org.openjdk.jmh.annotations.BenchmarkMode;
+import org.openjdk.jmh.annotations.Fork;
+import org.openjdk.jmh.annotations.Measurement;
+import org.openjdk.jmh.annotations.Mode;
+import org.openjdk.jmh.annotations.OutputTimeUnit;
+import org.openjdk.jmh.annotations.Scope;
+import org.openjdk.jmh.annotations.State;
+import org.openjdk.jmh.annotations.Threads;
+import org.openjdk.jmh.annotations.Warmup;
+
+import java.lang.reflect.Method;
+import java.util.Stack;
+import java.util.concurrent.TimeUnit;
+import java.util.function.Function;
+import java.util.stream.Stream;
+
+/**
+ * Benchmarks Log4j 2, Log4j 1, Logback and JUL using the ERROR level which is enabled for this test.
+ * The configuration for each writes to disk.
+ */
+// HOW TO RUN THIS TEST
+// java -jar target/benchmarks.jar ".*StackTraceBenchmark.*" -f 1 -i 10 -wi 20 -bm sample -tu ns
+@State(Scope.Thread)
+@Threads(1)
+@Fork(1)
+@Warmup(iterations = 3, time = 3)
+@Measurement(iterations = 3, time = 3)
+public class StackTraceBenchmark {
+
+    // Checkstyle Suppress: the lower-case 'u' ticks off CheckStyle...
+    // CHECKSTYLE:OFF
+    static final int JDK_7u25_OFFSET;
+    // CHECKSTYLE:OFF
+
+    private static final Method GET_CALLER_CLASS;
+
+    static {
+        Method getCallerClass;
+        int java7u25CompensationOffset = 0;
+        try {
+            final Class<?> sunReflectionClass = LoaderUtil.loadClass("sun.reflect.Reflection");
+            getCallerClass = sunReflectionClass.getDeclaredMethod("getCallerClass", int.class);
+            Object o = getCallerClass.invoke(null, 0);
+            getCallerClass.invoke(null, 0);
+            if (o == null || o != sunReflectionClass) {
+                getCallerClass = null;
+                java7u25CompensationOffset = -1;
+            } else {
+                o = getCallerClass.invoke(null, 1);
+                if (o == sunReflectionClass) {
+                    System.out.println("WARNING: Java 1.7.0_25 is in use which has a broken implementation of Reflection.getCallerClass(). " +
+                            " Please consider upgrading to Java 1.7.0_40 or later.");
+                    java7u25CompensationOffset = 1;
+                }
+            }
+        } catch (final Exception | LinkageError e) {
+            System.out.println("WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance.");
+            getCallerClass = null;
+            java7u25CompensationOffset = -1;
+        }
+
+        GET_CALLER_CLASS = getCallerClass;
+        JDK_7u25_OFFSET = java7u25CompensationOffset;
+    }
+
+    @BenchmarkMode(Mode.Throughput)
+    @OutputTimeUnit(TimeUnit.SECONDS)
+    @Benchmark
+    public Stack<Class<?>> defaultJava8() {
+        final Stack<Class<?>> classes = new Stack<>();
+        Class<?> clazz;
+        for (int i = 1; null != (clazz = getCallerClass(i)); i++) {
+            classes.push(clazz);
+        }
+        return classes;
+    }
+
+    public Class<?> getCallerClass(final int depth) {
+        if (depth < 0) {
+            throw new IndexOutOfBoundsException(Integer.toString(depth));
+        }
+        // note that we need to add 1 to the depth value to compensate for this method, but not for the Method.invoke
+        // since Reflection.getCallerClass ignores the call to Method.invoke()
+        try {
+            return (Class<?>) GET_CALLER_CLASS.invoke(null, depth + 1 + JDK_7u25_OFFSET);
+        } catch (final Exception e) {
+            // theoretically this could happen if the caller class were native code
+            // TODO: return Object.class
+            return null;
+        }
+    }
+
+    private final static StackWalker walker = StackWalker.getInstance(StackWalker.Option.RETAIN_CLASS_REFERENCE);
+
+    private static final Function<? super Stream<StackWalker.StackFrame>, ? extends Stack<Class<?>>> function = s -> {
+        Stack<Class<?>> stack = new Stack<Class<?>>();
+        s.map(StackWalker.StackFrame::getDeclaringClass).forEachOrdered(stack::add);
+        return stack;
+    };
+
+    @BenchmarkMode(Mode.Throughput)
+    @OutputTimeUnit(TimeUnit.SECONDS)
+    @Benchmark
+    public Stack<Class<?>> stackWalker() {
+        return walker.walk(function);
+    }
+
+    @BenchmarkMode(Mode.Throughput)
+    @OutputTimeUnit(TimeUnit.SECONDS)
+    @Benchmark
+    public Stack<Class<?>> securityManager() {
+        return PrivateSecurityManagerStackTraceUtil.getCurrentStackTrace();
+    }
+}