Hi java.util.logging maintainers, Here is a patch to improve the performance of LogRecord.inferCaller. This improves the performance of the microbenchmark in 6511515 by 5x. Swamy, please review. Contributed by Jeremy Manson. http://cr.openjdk.java.net/~martin/inferCaller
As a followon, it makes sense to allow full random access to elements of a stack trace. If that is done, this change would be simplified by not requiring SharedSecrets. # HG changeset patch # User martin # Date 1240268799 25200 # Node ID ba9c54ffcac48493a46ee902dae6809cf4678e8d # Parent 8b326aebb981265a99ed96355efe28f8c1b0a0c0 6511515: poor performance of LogRecord.inferCaller depending on java.lang.Throwable.getStackTraceElement Reviewed-by: swamyv Contributed-by: jeremymanson Summary: Allow random access to stack trace elements; retrieve only needed ones diff --git a/src/share/classes/java/lang/System.java b/src/share/classes/java/lang/System.java --- a/src/share/classes/java/lang/System.java +++ b/src/share/classes/java/lang/System.java @@ -1174,6 +1174,12 @@ public void registerShutdownHook(int slot, Runnable r) { Shutdown.add(slot, r); } + public int getStackTraceDepth(Throwable t) { + return t.getStackTraceDepth(); + } + public StackTraceElement getStackTraceElement(Throwable t, int i) { + return t.getStackTraceElement(i); + } }); } diff --git a/src/share/classes/java/lang/Throwable.java b/src/share/classes/java/lang/Throwable.java --- a/src/share/classes/java/lang/Throwable.java +++ b/src/share/classes/java/lang/Throwable.java @@ -645,17 +645,21 @@ /** * Returns the number of elements in the stack trace (or 0 if the stack * trace is unavailable). + * + * package-protection for use by SharedSecrets. */ - private native int getStackTraceDepth(); + native int getStackTraceDepth(); /** * Returns the specified element of the stack trace. + * + * package-protection for use by SharedSecrets. * * @param index index of the element to return. * @throws IndexOutOfBoundsException if <tt>index < 0 || * index >= getStackTraceDepth() </tt> */ - private native StackTraceElement getStackTraceElement(int index); + native StackTraceElement getStackTraceElement(int index); private synchronized void writeObject(java.io.ObjectOutputStream s) throws IOException diff --git a/src/share/classes/java/util/logging/LogRecord.java b/src/share/classes/java/util/logging/LogRecord.java --- a/src/share/classes/java/util/logging/LogRecord.java +++ b/src/share/classes/java/util/logging/LogRecord.java @@ -28,6 +28,9 @@ import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.atomic.AtomicLong; import java.io.*; + +import sun.misc.JavaLangAccess; +import sun.misc.SharedSecrets; /** * LogRecord objects are used to pass logging requests between @@ -522,29 +525,31 @@ // Private method to infer the caller's class and method names private void inferCaller() { needToInferCaller = false; - // Get the stack trace. - StackTraceElement stack[] = (new Throwable()).getStackTrace(); - // First, search back to a method in the Logger class. - int ix = 0; - while (ix < stack.length) { - StackTraceElement frame = stack[ix]; + JavaLangAccess access = SharedSecrets.getJavaLangAccess(); + Throwable throwable = new Throwable(); + int depth = access.getStackTraceDepth(throwable); + + String logClassName = "java.util.logging.Logger"; + boolean lookingForLogger = true; + for (int ix = 0; ix < depth; ix++) { + // Calling getStackTraceElement directly prevents the VM + // from paying the cost of building the entire stack frame. + StackTraceElement frame = + access.getStackTraceElement(throwable, ix); String cname = frame.getClassName(); - if (cname.equals("java.util.logging.Logger")) { - break; + if (lookingForLogger) { + // Skip all frames until we have found the first logger frame. + if (cname.equals(logClassName)) { + lookingForLogger = false; + } + } else { + if (!cname.equals(logClassName)) { + // We've found the relevant frame. + setSourceClassName(cname); + setSourceMethodName(frame.getMethodName()); + return; + } } - ix++; - } - // Now search for the first frame before the "Logger" class. - while (ix < stack.length) { - StackTraceElement frame = stack[ix]; - String cname = frame.getClassName(); - if (!cname.equals("java.util.logging.Logger")) { - // We've found the relevant frame. - setSourceClassName(cname); - setSourceMethodName(frame.getMethodName()); - return; - } - ix++; } // We haven't found a suitable frame, so just punt. This is // OK as we are only committed to making a "best effort" here. diff --git a/src/share/classes/sun/misc/JavaLangAccess.java b/src/share/classes/sun/misc/JavaLangAccess.java --- a/src/share/classes/sun/misc/JavaLangAccess.java +++ b/src/share/classes/sun/misc/JavaLangAccess.java @@ -57,4 +57,14 @@ /** register shutdown hook */ void registerShutdownHook(int slot, Runnable r); + + /** + * Returns the number of stack frames represented by the given throwable. + */ + int getStackTraceDepth(Throwable t); + + /** + * Returns the ith StackTraceElement for the given throwable. + */ + StackTraceElement getStackTraceElement(Throwable t, int i); }