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 2017/04/21 06:40:01 UTC
[05/11] logging-log4j2 git commit: LOG4J2-1359 - Benchmark impact on
LogEvent
LOG4J2-1359 - Benchmark impact on LogEvent
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/8eac9102
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/8eac9102
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/8eac9102
Branch: refs/heads/master
Commit: 8eac91024cce617b15838c1f630d8aa32703c6f3
Parents: e6ce8e4
Author: Ralph Goers <rg...@nextiva.com>
Authored: Sun Mar 19 12:30:56 2017 -0700
Committer: Ralph Goers <rg...@nextiva.com>
Committed: Sun Mar 19 12:30:56 2017 -0700
----------------------------------------------------------------------
.../logging/log4j/util/ReflectionUtil.java | 1 +
.../log4j/core/impl/LocationLocator.java | 9 ++
.../apache/logging/log4j/core/LogEventTest.java | 23 ++++
.../appender/db/jpa/LogEventEntityTest.java | 122 +++++++++++++++++++
.../core/appender/db/jpa/LogEventTest.java | 122 -------------------
.../log4j/core/impl/LocationLocator.java | 4 +
.../logging/log4j/util/ClassNamePredicate.java | 1 -
.../logging/log4j/util/ReflectionUtil.java | 16 ++-
log4j-perf/pom.xml | 3 +
.../log4j/perf/jmh/Log4jLogEventBenchmark.java | 25 +++-
.../log4j/perf/jmh/ReflectionBenchmark.java | 52 ++++++--
11 files changed, 240 insertions(+), 138 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/8eac9102/log4j-api/src/main/java/org/apache/logging/log4j/util/ReflectionUtil.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/util/ReflectionUtil.java b/log4j-api/src/main/java/org/apache/logging/log4j/util/ReflectionUtil.java
index 52f171e..74be0b2 100644
--- a/log4j-api/src/main/java/org/apache/logging/log4j/util/ReflectionUtil.java
+++ b/log4j-api/src/main/java/org/apache/logging/log4j/util/ReflectionUtil.java
@@ -61,6 +61,7 @@ public final class ReflectionUtil {
static {
Method getCallerClass;
int java7u25CompensationOffset = 0;
+ System.out.println("Using Java 7 ReflectionUtil");
try {
final Class<?> sunReflectionClass = LoaderUtil.loadClass("sun.reflect.Reflection");
getCallerClass = sunReflectionClass.getDeclaredMethod("getCallerClass", int.class);
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/8eac9102/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/LocationLocator.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/LocationLocator.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/LocationLocator.java
index 5f0187f..a47ea5b 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/LocationLocator.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/LocationLocator.java
@@ -21,6 +21,11 @@ package org.apache.logging.log4j.core.impl;
*/
public class LocationLocator {
+ static {
+ System.out.println("Using Java 7 Locator");
+ }
+
+
public static StackTraceElement calcLocation(final String fqcnOfLogger) {
if (fqcnOfLogger == null) {
return null;
@@ -37,4 +42,8 @@ public class LocationLocator {
}
return null;
}
+
+ public static StackTraceElement getStackTraceElement(final int depth) {
+ return new Throwable().getStackTrace()[depth];
+ }
}
\ No newline at end of file
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/8eac9102/log4j-core/src/test/java/org/apache/logging/log4j/core/LogEventTest.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/LogEventTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/LogEventTest.java
index 64589ae..d2f58a3 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/LogEventTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/LogEventTest.java
@@ -25,7 +25,9 @@ import java.io.ObjectOutputStream;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LoggingException;
import org.apache.logging.log4j.core.impl.Log4jLogEvent;
+import org.apache.logging.log4j.message.Message;
import org.apache.logging.log4j.message.SimpleMessage;
+import org.junit.BeforeClass;
import org.junit.Ignore;
import org.junit.Test;
@@ -36,6 +38,9 @@ import static org.junit.Assert.*;
*/
public class LogEventTest {
+ private static Message MESSAGE = new SimpleMessage("This is a test");
+ private static TestClass TESTER = new TestClass();
+
@Test
public void testSerialization() throws Exception {
final LogEvent event1 = Log4jLogEvent.newBuilder() //
@@ -147,4 +152,22 @@ public class LogEventTest {
assertNotEquals("Events should not be equal", event1, event2);
assertEquals("Events should be equal", event2, event3);
}
+
+ @Test
+ public void testLocation() {
+ StackTraceElement ste = TESTER.getEventSource(this.getClass().getName());
+ assertNotNull("No StackTraceElement", ste);
+ assertEquals("Incorrect event", this.getClass().getName(), ste.getClassName());
+ }
+
+ private static class TestClass {
+ private static final String FQCN = TestClass.class.getName();
+
+ public StackTraceElement getEventSource(String loggerName) {
+ final LogEvent event = Log4jLogEvent.newBuilder().setLoggerName(loggerName)
+ .setLoggerFqcn(FQCN).setLevel(Level.INFO).setMessage(MESSAGE).build();
+ event.setIncludeLocation(true);
+ return event.getSource();
+ }
+ }
}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/8eac9102/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/db/jpa/LogEventEntityTest.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/db/jpa/LogEventEntityTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/db/jpa/LogEventEntityTest.java
new file mode 100644
index 0000000..ed59b53
--- /dev/null
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/db/jpa/LogEventEntityTest.java
@@ -0,0 +1,122 @@
+/*
+ * 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.core.appender.db.jpa;
+
+import java.util.Map;
+
+import org.apache.logging.log4j.Level;
+import org.apache.logging.log4j.Marker;
+import org.apache.logging.log4j.ThreadContext.ContextStack;
+import org.apache.logging.log4j.core.LogEvent;
+import org.apache.logging.log4j.core.impl.ThrowableProxy;
+import org.apache.logging.log4j.message.Message;
+import org.junit.Assert;
+import org.junit.Test;
+
+public class LogEventEntityTest {
+
+ @Test
+ public void testToImmutable_AbstractLogEventWrapperEntity() {
+ final LogEvent logEvent = new AbstractLogEventWrapperEntity() {
+
+ private static final long serialVersionUID = 1L;
+
+ @Override
+ public Map<String, String> getContextMap() {
+ return null;
+ }
+
+ @Override
+ public ContextStack getContextStack() {
+ return null;
+ }
+
+ @Override
+ public Level getLevel() {
+ return null;
+ }
+
+ @Override
+ public String getLoggerFqcn() {
+ return null;
+ }
+
+ @Override
+ public String getLoggerName() {
+ return null;
+ }
+
+ @Override
+ public Marker getMarker() {
+ return null;
+ }
+
+ @Override
+ public Message getMessage() {
+ return null;
+ }
+
+ @Override
+ public long getNanoTime() {
+ return 0;
+ }
+
+ @Override
+ public StackTraceElement getSource() {
+ return null;
+ }
+
+ @Override
+ public long getThreadId() {
+ return 0;
+ }
+
+ @Override
+ public String getThreadName() {
+ return null;
+ }
+
+ @Override
+ public int getThreadPriority() {
+ return 0;
+ }
+
+ @Override
+ public Throwable getThrown() {
+ return null;
+ }
+
+ @Override
+ public ThrowableProxy getThrownProxy() {
+ return null;
+ }
+
+ @Override
+ public long getTimeMillis() {
+ return 0;
+ }
+ };
+ Assert.assertNotSame(logEvent, logEvent.toImmutable());
+ }
+
+ @Test
+ public void testToImmutable_TestBaseEntity() {
+ final LogEvent logEvent = new TestBaseEntity();
+ Assert.assertNotSame(logEvent, logEvent.toImmutable());
+ }
+}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/8eac9102/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/db/jpa/LogEventTest.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/db/jpa/LogEventTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/db/jpa/LogEventTest.java
deleted file mode 100644
index 5ab1e87..0000000
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/appender/db/jpa/LogEventTest.java
+++ /dev/null
@@ -1,122 +0,0 @@
-/*
- * 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.core.appender.db.jpa;
-
-import java.util.Map;
-
-import org.apache.logging.log4j.Level;
-import org.apache.logging.log4j.Marker;
-import org.apache.logging.log4j.ThreadContext.ContextStack;
-import org.apache.logging.log4j.core.LogEvent;
-import org.apache.logging.log4j.core.impl.ThrowableProxy;
-import org.apache.logging.log4j.message.Message;
-import org.junit.Assert;
-import org.junit.Test;
-
-public class LogEventTest {
-
- @Test
- public void testToImmutable_AbstractLogEventWrapperEntity() {
- final LogEvent logEvent = new AbstractLogEventWrapperEntity() {
-
- private static final long serialVersionUID = 1L;
-
- @Override
- public Map<String, String> getContextMap() {
- return null;
- }
-
- @Override
- public ContextStack getContextStack() {
- return null;
- }
-
- @Override
- public Level getLevel() {
- return null;
- }
-
- @Override
- public String getLoggerFqcn() {
- return null;
- }
-
- @Override
- public String getLoggerName() {
- return null;
- }
-
- @Override
- public Marker getMarker() {
- return null;
- }
-
- @Override
- public Message getMessage() {
- return null;
- }
-
- @Override
- public long getNanoTime() {
- return 0;
- }
-
- @Override
- public StackTraceElement getSource() {
- return null;
- }
-
- @Override
- public long getThreadId() {
- return 0;
- }
-
- @Override
- public String getThreadName() {
- return null;
- }
-
- @Override
- public int getThreadPriority() {
- return 0;
- }
-
- @Override
- public Throwable getThrown() {
- return null;
- }
-
- @Override
- public ThrowableProxy getThrownProxy() {
- return null;
- }
-
- @Override
- public long getTimeMillis() {
- return 0;
- }
- };
- Assert.assertNotSame(logEvent, logEvent.toImmutable());
- }
-
- @Test
- public void testToImmutable_TestBaseEntity() {
- final LogEvent logEvent = new TestBaseEntity();
- Assert.assertNotSame(logEvent, logEvent.toImmutable());
- }
-}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/8eac9102/log4j-java9/src/main/java/org/apache/logging/log4j/core/impl/LocationLocator.java
----------------------------------------------------------------------
diff --git a/log4j-java9/src/main/java/org/apache/logging/log4j/core/impl/LocationLocator.java b/log4j-java9/src/main/java/org/apache/logging/log4j/core/impl/LocationLocator.java
index 5408533..8fe5f8d 100644
--- a/log4j-java9/src/main/java/org/apache/logging/log4j/core/impl/LocationLocator.java
+++ b/log4j-java9/src/main/java/org/apache/logging/log4j/core/impl/LocationLocator.java
@@ -27,4 +27,8 @@ public class LocationLocator {
public static StackTraceElement calcLocation(final String fqcnOfLogger) {
return walker.walk(s -> s.filter(new ClassNamePredicate(fqcnOfLogger)).findFirst()).get().toStackTraceElement();
}
+
+ public static StackTraceElement getStackTraceElement(final int depth) {
+ return walker.walk(s -> s.skip(depth - 1)).findFirst().get().toStackTraceElement();
+ }
}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/8eac9102/log4j-java9/src/main/java/org/apache/logging/log4j/util/ClassNamePredicate.java
----------------------------------------------------------------------
diff --git a/log4j-java9/src/main/java/org/apache/logging/log4j/util/ClassNamePredicate.java b/log4j-java9/src/main/java/org/apache/logging/log4j/util/ClassNamePredicate.java
index 2d9314d..063e538 100644
--- a/log4j-java9/src/main/java/org/apache/logging/log4j/util/ClassNamePredicate.java
+++ b/log4j-java9/src/main/java/org/apache/logging/log4j/util/ClassNamePredicate.java
@@ -33,7 +33,6 @@ public final class ClassNamePredicate implements Predicate<StackWalker.StackFram
@Override
public boolean test(StackWalker.StackFrame f) {
- System.out.println(f.getClassName());
if (fqcn.equals(f.getClassName())) {
next = true;
return false;
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/8eac9102/log4j-java9/src/main/java/org/apache/logging/log4j/util/ReflectionUtil.java
----------------------------------------------------------------------
diff --git a/log4j-java9/src/main/java/org/apache/logging/log4j/util/ReflectionUtil.java b/log4j-java9/src/main/java/org/apache/logging/log4j/util/ReflectionUtil.java
index 34d687a..31bb94b 100644
--- a/log4j-java9/src/main/java/org/apache/logging/log4j/util/ReflectionUtil.java
+++ b/log4j-java9/src/main/java/org/apache/logging/log4j/util/ReflectionUtil.java
@@ -16,7 +16,9 @@
*/
package org.apache.logging.log4j.util;
-import java.util.function.Predicate;
+import java.util.List;
+import java.util.Stack;
+import java.util.stream.Collectors;
/**
* <em>Consider this class private.</em> Determines the caller's class.
@@ -36,4 +38,16 @@ public class ReflectionUtil {
public static Class<?> getCallerClass(final Class<?> anchor) {
return walker.walk(s -> s.filter(new ClassPredicate(anchor)).findFirst()).get().getDeclaringClass();
}
+
+ public static Class<?> getCallerClass(final int depth) {
+ return walker.walk(s -> s.skip(depth - 1)).findFirst().get().getDeclaringClass();
+ }
+
+ public static Stack<Class<?>> getCurrentStackTrace() {
+ Stack<Class<?>> stack = new Stack<Class<?>>();
+ List<Class<?>> classes = walker.walk(s -> s.map(f -> f.getDeclaringClass()).collect(Collectors.toList()));
+ stack.addAll(classes);
+ return stack;
+ }
+
}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/8eac9102/log4j-perf/pom.xml
----------------------------------------------------------------------
diff --git a/log4j-perf/pom.xml b/log4j-perf/pom.xml
index 4b9d92b..c286d88 100644
--- a/log4j-perf/pom.xml
+++ b/log4j-perf/pom.xml
@@ -168,6 +168,9 @@
<transformers>
<transformer implementation="org.apache.maven.plugins.shade.resource.ManifestResourceTransformer">
<mainClass>org.openjdk.jmh.Main</mainClass>
+ <manifestEntries>
+ <Multi-Release>true</Multi-Release>
+ </manifestEntries>
</transformer>
</transformers>
<filters>
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/8eac9102/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4jLogEventBenchmark.java
----------------------------------------------------------------------
diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4jLogEventBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4jLogEventBenchmark.java
index 225fad6..4e3a303 100644
--- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4jLogEventBenchmark.java
+++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/Log4jLogEventBenchmark.java
@@ -33,11 +33,13 @@ import org.openjdk.jmh.infra.Blackhole;
public class Log4jLogEventBenchmark {
private static Message MESSAGE;
private static Throwable ERROR;
+ private static TestClass TESTER;
@Setup
public void setup() {
MESSAGE = new SimpleMessage("Test message");
ERROR = new Exception("test");
+ TESTER = new TestClass();
}
@Benchmark
@@ -63,10 +65,8 @@ public class Log4jLogEventBenchmark {
@Benchmark
public StackTraceElement getSourceLocationOfLogEvent() {
- final LogEvent event = Log4jLogEvent.newBuilder().setLoggerName(this.getClass().getName())
- .setLoggerFqcn(this.getClass().getName()).setLevel(Level.INFO).setMessage(MESSAGE).build();
- event.setIncludeLocation(true);
- return event.getSource();
+
+ return TESTER.getEventSource(this.getClass().getName());
}
@Benchmark
@@ -76,11 +76,28 @@ public class Log4jLogEventBenchmark {
}
@Benchmark
+ public Serializable createSerializableLogEventProxyWithoutExceptionWithLocation() {
+ final Log4jLogEvent event = new Log4jLogEvent("a.b.c", null, "a.b.c", Level.INFO, MESSAGE, null, null);
+ return Log4jLogEvent.serialize(event, true);
+ }
+
+ @Benchmark
public Serializable createSerializableLogEventProxyWithException(final Blackhole bh) {
final Log4jLogEvent event = new Log4jLogEvent("a.b.c", null, "a.b.c", Level.INFO, MESSAGE, null, ERROR);
return Log4jLogEvent.serialize(event, false);
}
+ private static class TestClass {
+ private static final String FQCN = TestClass.class.getName();
+
+ public StackTraceElement getEventSource(String loggerName) {
+ final LogEvent event = Log4jLogEvent.newBuilder().setLoggerName(loggerName)
+ .setLoggerFqcn(FQCN).setLevel(Level.INFO).setMessage(MESSAGE).build();
+ event.setIncludeLocation(true);
+ return event.getSource();
+ }
+ }
+
// ============================== HOW TO RUN THIS TEST: ====================================
//
// In sampling mode (latency test):
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/8eac9102/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ReflectionBenchmark.java
----------------------------------------------------------------------
diff --git a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ReflectionBenchmark.java b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ReflectionBenchmark.java
index 08f6a3d..97fb2a8 100644
--- a/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ReflectionBenchmark.java
+++ b/log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/ReflectionBenchmark.java
@@ -20,6 +20,7 @@ import java.lang.reflect.Constructor;
import java.lang.reflect.InvocationTargetException;
import java.util.Random;
+import org.apache.logging.log4j.core.impl.LocationLocator;
import org.apache.logging.log4j.message.Message;
import org.apache.logging.log4j.message.StringFormattedMessage;
import org.apache.logging.log4j.util.ReflectionUtil;
@@ -28,7 +29,6 @@ import org.openjdk.jmh.annotations.Level;
import org.openjdk.jmh.annotations.Scope;
import org.openjdk.jmh.annotations.Setup;
import org.openjdk.jmh.annotations.State;
-import sun.reflect.Reflection;
/**
* <p>
@@ -88,10 +88,6 @@ public class ReflectionBenchmark {
return ReflectionUtil.getCallerClass(3).getName();
}
- @Benchmark
- public String test04_getCallerClassNameSunReflection() {
- return Reflection.getCallerClass(3).getName();
- }
@Benchmark
public Class<?> test05_getStackTraceClassForClassName() throws ClassNotFoundException {
@@ -109,11 +105,6 @@ public class ReflectionBenchmark {
}
@Benchmark
- public Class<?> test08_getDirectSunReflection() {
- return Reflection.getCallerClass(3);
- }
-
- @Benchmark
public Message test09_getMessageUsingNew(final RandomInteger rng) {
return new StringFormattedMessage("Hello %i", rng.random);
}
@@ -142,4 +133,45 @@ public class ReflectionBenchmark {
return classContextManager.getClassContext();
}
+
+ @Benchmark
+ public Class<?> reflectionUtilGetClass() {
+ return new ClassLocator().findClass(4);
+ }
+
+ @Benchmark
+ public String locationLocatorGetMethod() {
+ return new MethodLocator().findMethodName(4);
+ }
+
+ private static class ClassLocator {
+
+ private Class<?> findClass(int depth) {
+ if (depth == 1) {
+ return locateCaller();
+ } else {
+ return findClass(depth - 1);
+ }
+ }
+
+ private Class<?> locateCaller() {
+ return ReflectionUtil.getCallerClass(ClassLocator.class.getName());
+ }
+ }
+
+ private static class MethodLocator {
+
+ private String findMethodName(int depth) {
+ if (depth == 1) {
+ return locateMethodName();
+ } else {
+ return findMethodName(depth - 1);
+ }
+ }
+
+ private String locateMethodName() {
+ return LocationLocator.calcLocation(MethodLocator.class.getName()).getMethodName();
+ }
+ }
+
}