Repository: logging-log4j2 Updated Branches: refs/heads/master a26dab9b4 -> 48f3a4ed9
Add unified caller class utility class. - Based on ReflectiveCallerClassUtility. - Adds getCallerClass(String) which is primarily used by ClassLoaderContextSelector. - Adds getCurrentStackTrace() which is ported from ThrowableProxy. - Adds a rather complete implementation of getCallerClass(int) based on Throwable. - Unit tests. - Updates benchmark tests accordingly. - Will also help us maintain future compatibility with JDK 9 and beyond (hooray for tests!) Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/3d76316a Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/3d76316a Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/3d76316a Branch: refs/heads/master Commit: 3d76316ab85330ae0c36f56c7bf3c287f156f51c Parents: 0e9e331 Author: Matt Sicker <[email protected]> Authored: Fri Sep 5 16:52:29 2014 -0500 Committer: Matt Sicker <[email protected]> Committed: Fri Sep 5 16:52:48 2014 -0500 ---------------------------------------------------------------------- .../logging/log4j/util/ReflectionUtil.java | 276 +++++++++++++++++++ .../logging/log4j/util/ReflectionUtilTest.java | 94 +++++++ .../log4j/perf/jmh/ReflectionBenchmark.java | 6 +- 3 files changed, 373 insertions(+), 3 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3d76316a/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 new file mode 100644 index 0000000..c9e010b --- /dev/null +++ b/log4j-api/src/main/java/org/apache/logging/log4j/util/ReflectionUtil.java @@ -0,0 +1,276 @@ +/* + * 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.util; + +import java.lang.reflect.Method; +import java.util.Stack; + +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.status.StatusLogger; + +/** + * <em>Consider this class private.</em> Provides various methods to determine the caller class. + * <h3>Background</h3> + * <p>This method, available only in the Oracle/Sun/OpenJDK implementations of the Java + * Virtual Machine, is a much more efficient mechanism for determining the {@link Class} of the caller of a particular + * method. When it is not available, a {@link SecurityManager} is the second-best option. When this is also not + * possible, the {@code StackTraceElement[]} returned by {@link Throwable#getStackTrace()} must be used, and its + * {@code String} class name converted to a {@code Class} using the slow {@link Class#forName} (which can add an extra + * microsecond or more for each invocation depending on the runtime ClassLoader hierarchy). + * </p> + * <p> + * During Java 8 development, the {@code sun.reflect.Reflection.getCallerClass(int)} was removed from OpenJDK, and this + * change was back-ported to Java 7 in version 1.7.0_25 which changed the behavior of the call and caused it to be off + * by one stack frame. This turned out to be beneficial for the survival of this API as the change broke hundreds of + * libraries and frameworks relying on the API which brought much more attention to the intended API removal. + * </p> + * <p> + * After much community backlash, the JDK team agreed to restore {@code getCallerClass(int)} and keep its existing + * behavior for the rest of Java 7. However, the method is deprecated in Java 8, and current Java 9 development has not + * addressed this API. Therefore, the functionality of this class cannot be relied upon for all future versions of + * Java. It does, however, work just fine in Sun JDK 1.6, OpenJDK 1.6, Oracle/OpenJDK 1.7, and Oracle/OpenJDK 1.8. + * Other Java environments may fall back to using {@link Throwable#getStackTrace()} which is significantly slower due + * to examination of every virtual frame of execution. + * </p> + */ +public final class ReflectionUtil { + + private static final Logger LOGGER = StatusLogger.getLogger(); + + private static final boolean SUN_REFLECTION_SUPPORTED; + private static final Method GET_CALLER_CLASS; + static final int JDK_7u25_OFFSET; + private static final PrivateSecurityManager SECURITY_MANAGER; + + static { + Method getCallerClass; + int java7u25CompensationOffset = 0; + try { + final Class<?> sunReflectionClass = LoaderUtil.getThreadContextClassLoader().loadClass( + "sun.reflect.Reflection"); + getCallerClass = sunReflectionClass.getDeclaredMethod("getCallerClass", int.class); + Object o = getCallerClass.invoke(null, 0); + final Object test1 = getCallerClass.invoke(null, 0); + if (o == null || o != sunReflectionClass) { + LOGGER.warn("Unexpected return value from Reflection.getCallerClass(): {}", test1); + getCallerClass = null; + java7u25CompensationOffset = -1; + } else { + o = getCallerClass.invoke(null, 1); + if (o == sunReflectionClass) { + LOGGER.warn( + "You are using Java 1.7.0_25 which has a broken implementation of Reflection.getCallerClass."); + LOGGER.warn("You should upgrade to at least Java 1.7.0_40 or later."); + LOGGER.debug("Using stack depth compensation offset of 1 due to Java 7u25."); + java7u25CompensationOffset = 1; + } + } + } catch (final Exception e) { + LOGGER.info("sun.reflect.Reflection.getCallerClass is not supported. " + + "ReflectionUtil.getCallerClass will be much slower due to this.", e); + getCallerClass = null; + java7u25CompensationOffset = -1; + } + + SUN_REFLECTION_SUPPORTED = getCallerClass != null; + GET_CALLER_CLASS = getCallerClass; + JDK_7u25_OFFSET = java7u25CompensationOffset; + + PrivateSecurityManager psm; + if (!SUN_REFLECTION_SUPPORTED) { + try { + final SecurityManager sm = System.getSecurityManager(); + if (sm != null) { + sm.checkPermission(new RuntimePermission("createSecurityManager")); + } + psm = new PrivateSecurityManager(); + } catch (final SecurityException ignored) { + LOGGER.debug( + "Not allowed to create SecurityManager. Falling back to slowest ReflectionUtil implementation."); + psm = null; + } + } else { + psm = null; + } + SECURITY_MANAGER = psm; + } + + public static boolean supportsFastReflection() { + return SUN_REFLECTION_SUPPORTED; + } + + // migrated from ReflectiveCallerClassUtility + public static 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() + if (supportsFastReflection()) { + 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 + LOGGER.error("Error in ReflectionUtil.getCallerClass({}).", depth, e); + return null; + } + } + // TODO: SecurityManager-based version? + // slower fallback method using stack trace + final StackTraceElement element = getEquivalentStackTraceElement(depth + 1); + final ClassLoader cl = LoaderUtil.getThreadContextClassLoader(); + try { + return cl.loadClass(element.getClassName()); + } catch (final ClassNotFoundException e) { + LOGGER.error("Could not find class in ReflectionUtil.getCallerClass({}).", depth, e); + } + return null; + } + + static StackTraceElement getEquivalentStackTraceElement(final int depth) { + // (MS) I tested the difference between using Throwable.getStackTrace() and Thread.getStackTrace(), and + // the version using Throwable was surprisingly faster! at least on Java 1.8. See ReflectionBenchmark. + final StackTraceElement[] elements = new Throwable().getStackTrace(); + int i = 0; + for (final StackTraceElement element : elements) { + if (isValid(element)) { + if (i == depth) { + return element; + } else { + ++i; + } + } + } + LOGGER.error("Could not find an appropriate StackTraceElement at index {}", depth); + throw new IndexOutOfBoundsException(Integer.toString(depth)); + } + + private static boolean isValid(final StackTraceElement element) { + // ignore native methods (oftentimes are repeated frames) + if (element.isNativeMethod()) { + return false; + } + final String cn = element.getClassName(); + // ignore OpenJDK internal classes involved with reflective invocation + if (cn.startsWith("sun.reflect.")) { + return false; + } + final String mn = element.getMethodName(); + // ignore use of reflection including: + // Method.invoke + // InvocationHandler.invoke + // Constructor.newInstance + if (cn.startsWith("java.lang.reflect.") && (mn.equals("invoke") || mn.equals("newInstance"))) { + return false; + } + // ignore Class.newInstance + if (cn.equals("java.lang.Class") && mn.equals("newInstance")) { + return false; + } + // ignore use of Java 1.7+ MethodHandle.invokeFoo() methods + if (cn.equals("java.lang.invoke.MethodHandle") && mn.startsWith("invoke")) { + return false; + } + // any others? + return true; + } + + // migrated from ClassLoaderContextSelector + public static Class<?> getCallerClass(final String fqcn) { + if (supportsFastReflection()) { + boolean next = false; + Class<?> clazz; + for (int i = 2; null != (clazz = getCallerClass(i)); i++) { + if (fqcn.equals(clazz.getName())) { + next = true; + continue; + } + if (next) { + return clazz; + } + } + return null; + } + if (SECURITY_MANAGER != null) { + return SECURITY_MANAGER.getCallerClass(fqcn); + } + boolean next = false; + final StackTraceElement[] elements = new Throwable().getStackTrace(); + try { + for (final StackTraceElement element : elements) { + final String className = element.getClassName(); + if (className.equals(fqcn)) { + next = true; + continue; + } + if (next) { + return LoaderUtil.getThreadContextClassLoader().loadClass(className); + } + } + } catch (final ClassNotFoundException ignored) { + // no problem really + } + return null; + } + + // migrated from ThrowableProxy + public static Stack<Class<?>> getCurrentStackTrace() { + if (supportsFastReflection()) { + final Stack<Class<?>> classes = new Stack<Class<?>>(); + Class<?> clazz; + for (int i = 1; null != (clazz = getCallerClass(i)); i++) { + classes.push(clazz); + } + return classes; + } else if (SECURITY_MANAGER != null) { + final Class<?>[] array = SECURITY_MANAGER.getClassContext(); + final Stack<Class<?>> classes = new Stack<Class<?>>(); + for (final Class<?> clazz : array) { + classes.push(clazz); + } + return classes; + } + return new Stack<Class<?>>(); + } + + static final class PrivateSecurityManager extends SecurityManager { + + @Override + protected Class<?>[] getClassContext() { + return super.getClassContext(); + } + + protected Class<?> getCallerClass(final String fqcn) { + final Class<?>[] classes = getClassContext(); + boolean next = false; + for (final Class<?> clazz : classes) { + if (fqcn.equals(clazz.getName())) { + next = true; + continue; + } + if (next) { + return clazz; + } + } + return null; + } + + } + + private ReflectionUtil() { + } +} http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3d76316a/log4j-api/src/test/java/org/apache/logging/log4j/util/ReflectionUtilTest.java ---------------------------------------------------------------------- diff --git a/log4j-api/src/test/java/org/apache/logging/log4j/util/ReflectionUtilTest.java b/log4j-api/src/test/java/org/apache/logging/log4j/util/ReflectionUtilTest.java new file mode 100644 index 0000000..95fb0ad --- /dev/null +++ b/log4j-api/src/test/java/org/apache/logging/log4j/util/ReflectionUtilTest.java @@ -0,0 +1,94 @@ +/* + * 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.util; + +import java.util.Stack; + +import org.junit.Before; +import org.junit.Test; +import org.junit.runners.BlockJUnit4ClassRunner; +import sun.reflect.Reflection; + +import static org.junit.Assert.*; +import static org.junit.Assume.assumeTrue; + +public class ReflectionUtilTest { + + @Before + public void setUp() throws Exception { + assumeTrue(ReflectionUtil.supportsFastReflection()); + } + + @Test + public void testSunReflectionEquivalence() throws Exception { + // can't start at 0 because Reflection != ReflectionUtil + for (int i = 1; i < 6; i++) { + assertSame( + Reflection.getCallerClass(i + ReflectionUtil.JDK_7u25_OFFSET), + ReflectionUtil.getCallerClass(i) + ); + } + } + + @Test + public void testStackTraceEquivalence() throws Exception { + for (int i = 1; i < 15; i++) { + final Class<?> expected = Reflection.getCallerClass(i + ReflectionUtil.JDK_7u25_OFFSET); + final Class<?> actual = ReflectionUtil.getCallerClass(i); + final Class<?> fallbackActual = Class.forName( + ReflectionUtil.getEquivalentStackTraceElement(i).getClassName()); + assertSame(expected, actual); + assertSame(expected, fallbackActual); + } + } + + @Test + public void testGetCallerClass() throws Exception { + final Class<?> expected = ReflectionUtilTest.class; + final Class<?> actual = ReflectionUtil.getCallerClass(1); + assertSame(expected, actual); + } + + @Test + public void testGetCallerClassNameViaStackTrace() throws Exception { + final Class<?> expected = ReflectionUtilTest.class; + final Class<?> actual = Class.forName(new Throwable().getStackTrace()[0].getClassName()); + assertSame(expected, actual); + } + + @Test + public void testGetCurrentStackTrace() throws Exception { + final Stack<Class<?>> classes = ReflectionUtil.getCurrentStackTrace(); + Class<?> prev = null; + Class<?> next = null; + while (!classes.empty()) { + prev = next; + next = classes.pop(); +// System.out.println(next); + } + assertSame(ReflectionUtilTest.class, prev); + } + + @Test + public void testGetCallerClassViaName() throws Exception { + final Class<?> expected = BlockJUnit4ClassRunner.class; + final Class<?> actual = ReflectionUtil.getCallerClass("org.junit.runners.ParentRunner"); + // if this test fails in the future, it's probably because of a JUnit upgrade; check the new stack trace and + // update this test accordingly + assertSame(expected, actual); + } +} \ No newline at end of file http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3d76316a/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 2d98f6b..21c8551 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,9 +20,9 @@ import java.lang.reflect.Constructor; import java.lang.reflect.InvocationTargetException; import java.util.Random; -import org.apache.logging.log4j.core.impl.ReflectiveCallerClassUtility; import org.apache.logging.log4j.message.Message; import org.apache.logging.log4j.message.StringFormattedMessage; +import org.apache.logging.log4j.util.ReflectionUtil; import org.openjdk.jmh.annotations.GenerateMicroBenchmark; import org.openjdk.jmh.annotations.Level; import org.openjdk.jmh.annotations.Scope; @@ -72,7 +72,7 @@ public class ReflectionBenchmark { @GenerateMicroBenchmark public String test03_getCallerClassNameReflectively() { - return ReflectiveCallerClassUtility.getCaller(3).getName(); + return ReflectionUtil.getCallerClass(3).getName(); } @GenerateMicroBenchmark @@ -92,7 +92,7 @@ public class ReflectionBenchmark { @GenerateMicroBenchmark public Class<?> test07_getReflectiveCallerClassUtility() { - return ReflectiveCallerClassUtility.getCaller(3); + return ReflectionUtil.getCallerClass(3); } @GenerateMicroBenchmark
