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 <[email protected]> Authored: Wed Aug 8 10:22:52 2018 -0400 Committer: Carter Kozak <[email protected]> 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(); + } +}
