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 2020/07/20 05:16:17 UTC
[logging-log4j2] branch release-2.x updated: LOG4J2-2880 - Add
StackWalker benchmark. Revert back to using StackWalker.walk based on
performance results
This is an automated email from the ASF dual-hosted git repository.
rgoers pushed a commit to branch release-2.x
in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
The following commit(s) were added to refs/heads/release-2.x by this push:
new d3fb653 LOG4J2-2880 - Add StackWalker benchmark. Revert back to using StackWalker.walk based on performance results
d3fb653 is described below
commit d3fb653f3c3b2dba52f35f12ee7fe622b6fdc040
Author: Ralph Goers <rg...@apache.org>
AuthorDate: Sun Jul 19 22:15:52 2020 -0700
LOG4J2-2880 - Add StackWalker benchmark. Revert back to using StackWalker.walk based on performance results
---
.../apache/logging/log4j/util/StackLocator.java | 37 +-----
.../logging/log4j/perf/jmh/StackWalkBenchmark.java | 129 +++++++++++++++++++++
.../logging/log4j/perf/util/StackDriver.java | 47 ++++++++
3 files changed, 182 insertions(+), 31 deletions(-)
diff --git a/log4j-api-java9/src/main/java/org/apache/logging/log4j/util/StackLocator.java b/log4j-api-java9/src/main/java/org/apache/logging/log4j/util/StackLocator.java
index 12e4e2a..c19670c 100644
--- a/log4j-api-java9/src/main/java/org/apache/logging/log4j/util/StackLocator.java
+++ b/log4j-api-java9/src/main/java/org/apache/logging/log4j/util/StackLocator.java
@@ -33,9 +33,6 @@ public class StackLocator {
private final static StackLocator INSTANCE = new StackLocator();
- private final static ThreadLocal<String> FQCN = new ThreadLocal<>();
- private final static FqcnCallerLocator LOCATOR = new FqcnCallerLocator();
-
public static StackLocator getInstance() {
return INSTANCE;
}
@@ -75,36 +72,14 @@ public class StackLocator {
}
public StackTraceElement calcLocation(final String fqcnOfLogger) {
- FQCN.set(fqcnOfLogger);
- final StackWalker.StackFrame walk = walker.walk(LOCATOR);
- final StackTraceElement element = walk == null ? null : walk.toStackTraceElement();
- FQCN.set(null);
- return element;
+ return stackWalker.walk(
+ s -> s.dropWhile(f -> !f.getClassName().equals(fqcnOfLogger)) // drop the top frames until we reach the logger
+ .dropWhile(f -> f.getClassName().equals(fqcnOfLogger)) // drop the logger frames
+ .findFirst()).map(StackWalker.StackFrame::toStackTraceElement).orElse(null);
}
public StackTraceElement getStackTraceElement(final int depth) {
- return stackWalker.walk(s -> s.skip(depth).findFirst()).get().toStackTraceElement();
- }
-
- static final class FqcnCallerLocator implements Function<Stream<StackWalker.StackFrame>, StackWalker.StackFrame> {
-
- @Override
- public StackWalker.StackFrame apply(Stream<StackWalker.StackFrame> stackFrameStream) {
- String fqcn = FQCN.get();
- boolean foundFqcn = false;
- Object[] frames = stackFrameStream.toArray();
- for (int i = 0; i < frames.length ; ++i) {
- final String className = ((StackWalker.StackFrame) frames[i]).getClassName();
- if (!foundFqcn) {
- // Skip frames until we find the FQCN
- foundFqcn = className.equals(fqcn);
- } else if (!className.equals(fqcn)) {
- // The frame is no longer equal to the FQCN so it is the one we want.
- return (StackWalker.StackFrame) frames[i];
- } // Otherwise it is equal to the FQCN so we need to skip it.
- }
- // Should never happen
- return null;
- }
+ return stackWalker.walk(s -> s.skip(depth).findFirst())
+ .map(StackWalker.StackFrame::toStackTraceElement).orElse(null);
}
}
diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/StackWalkBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/StackWalkBenchmark.java
new file mode 100644
index 0000000..d317164
--- /dev/null
+++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/StackWalkBenchmark.java
@@ -0,0 +1,129 @@
+/*
+ * 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 java.util.concurrent.TimeUnit;
+import java.util.function.Function;
+import java.util.stream.Stream;
+
+import org.apache.logging.log4j.perf.util.StackDriver;
+import org.openjdk.jmh.annotations.Benchmark;
+import org.openjdk.jmh.annotations.BenchmarkMode;
+import org.openjdk.jmh.annotations.Mode;
+import org.openjdk.jmh.annotations.OutputTimeUnit;
+import org.openjdk.jmh.annotations.Param;
+import org.openjdk.jmh.annotations.Scope;
+import org.openjdk.jmh.annotations.State;
+import org.openjdk.jmh.infra.Blackhole;
+
+/**
+ * Benchmark logging with logging disabled.
+ * // ============================== HOW TO RUN THIS TEST: ====================================
+ * //
+ * // single thread:
+ * // java -jar log4j-perf/target/benchmarks.jar ".*StackWalkBenchmark.*" -f 1 -wi 5 -i 10
+ * //
+ * // multiple threads (for example, 4 threads):
+ * // java -jar log4j-perf/target/benchmarks.jar ".*StackWalkBenchmark.*" -f 1 -wi 5 -i 10 -t 4 -si true
+ * //
+ * // Usage help:
+ * // java -jar log4j-perf/target/benchmarks.jar -help
+ * //
+ */
+@State(Scope.Benchmark)
+@BenchmarkMode(Mode.AverageTime)
+@OutputTimeUnit(TimeUnit.MICROSECONDS)
+public class StackWalkBenchmark {
+
+ private static final StackDriver stackDriver = new StackDriver();
+ private final static ThreadLocal<String> FQCN = new ThreadLocal<>();
+ private final static FqcnCallerLocator LOCATOR = new FqcnCallerLocator();
+ private final static StackWalker walker = StackWalker.getInstance(StackWalker.Option.RETAIN_CLASS_REFERENCE);
+
+ @Param({"10", "20", "50"})
+ private int initialDepth;
+
+ @Param({"5", "10", "20"})
+ private int callDepth;
+
+ @Benchmark
+ public void throwableSearch(Blackhole bh) {
+
+ stackDriver.deepCall(initialDepth, callDepth, (fqcn) -> {
+ final StackTraceElement[] stackTrace = new Throwable().getStackTrace();
+ boolean found = false;
+ for (int i = 0; i < stackTrace.length; i++) {
+ final String className = stackTrace[i].getClassName();
+ if (fqcn.equals(className)) {
+ found = true;
+ continue;
+ }
+ if (found && !fqcn.equals(className)) {
+ return stackTrace[i];
+ }
+ }
+ return null;
+ });
+ }
+
+ @Benchmark
+ public void stackWalkerWalk(Blackhole bh) {
+ stackDriver.deepCall(initialDepth, callDepth, (fqcn) -> {
+ return walker.walk(
+ s -> s.dropWhile(f -> !f.getClassName().equals(fqcn)) // drop the top frames until we reach the logger
+ .dropWhile(f -> f.getClassName().equals(fqcn)) // drop the logger frames
+ .findFirst())
+ .get()
+ .toStackTraceElement();
+ });
+ }
+
+ @Benchmark
+ public void stackWalkerArray(Blackhole bh) {
+
+ stackDriver.deepCall(initialDepth, callDepth, (fqcn) -> {
+ FQCN.set(fqcn);
+ final StackWalker.StackFrame walk = walker.walk(LOCATOR);
+ final StackTraceElement element = walk == null ? null : walk.toStackTraceElement();
+ FQCN.set(null);
+ return element;
+ });
+ }
+
+ static final class FqcnCallerLocator implements Function<Stream<StackWalker.StackFrame>, StackWalker.StackFrame> {
+
+ @Override
+ public StackWalker.StackFrame apply(Stream<StackWalker.StackFrame> stackFrameStream) {
+ String fqcn = FQCN.get();
+ boolean foundFqcn = false;
+ Object[] frames = stackFrameStream.toArray();
+ for (int i = 0; i < frames.length ; ++i) {
+ final String className = ((StackWalker.StackFrame) frames[i]).getClassName();
+ if (!foundFqcn) {
+ // Skip frames until we find the FQCN
+ foundFqcn = className.equals(fqcn);
+ } else if (!className.equals(fqcn)) {
+ // The frame is no longer equal to the FQCN so it is the one we want.
+ return (StackWalker.StackFrame) frames[i];
+ } // Otherwise it is equal to the FQCN so we need to skip it.
+ }
+ // Should never happen
+ return null;
+ }
+ }
+
+}
diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/util/StackDriver.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/util/StackDriver.java
new file mode 100644
index 0000000..9f239e4
--- /dev/null
+++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/util/StackDriver.java
@@ -0,0 +1,47 @@
+/*
+ * 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.util;
+
+import java.util.function.BiFunction;
+import java.util.function.Function;
+
+/**
+ * Facilitates creating a Call Stack for testing the performance of walkign it.
+ */
+public class StackDriver {
+ public StackTraceElement deepCall(int initialDepth, Integer targetDepth, Function<String, StackTraceElement> supplier) {
+ if (--initialDepth == 0) {
+ Processor processor = new Processor();
+ return processor.apply(targetDepth, supplier);
+ } else {
+ return deepCall(initialDepth, targetDepth, supplier);
+ }
+ }
+
+ public static class Processor implements BiFunction<Integer, Function<String, StackTraceElement>, StackTraceElement> {
+ private static final String FQCN = Processor.class.getName();
+
+ @Override
+ public StackTraceElement apply(Integer depth, Function<String, StackTraceElement> function) {
+ if (--depth == 0) {
+ return function.apply(FQCN);
+ } else {
+ return apply(depth, function);
+ }
+ }
+ }
+}