Review request 8153912: StackFrame::getFileName andStackFrame::getLineNumber not needed
timo.kinnunen at gmail.com
Tue Mar 14 16:00:25 UTC 2017
I was curious so I tried my hand at a couple of different implementations for getting a caller’s class. These were all run in JDK 1.8.0_102, VM 25.102-b14.
I’m not sure our results agree, but neither am I sure how to properly compare them. And since you have no baseline score this makes comparison that much harder. I also noticed that my baseline more than doubled after I started randomizing the calling stack, so this all seems pretty tricky to me in general.
This is what I see on my computer:
Benchmark Mode Cnt Score Error Units
GetCallerClass.baseline avgt 5 181.628 ± 1.945 ns/op
GetCallerClass.custom_SecurityManager_getClassContext avgt 5 3338.956 ± 29.751 ns/op
GetCallerClass.exception_Throwable_getStackTrace_v1 avgt 5 52768.248 ± 928.263 ns/op
GetCallerClass.exception_Throwable_getStackTrace_v2 avgt 5 49930.420 ± 774.868 ns/op
GetCallerClass.exception_Throwable_getStackTrace_v3 avgt 5 49911.325 ± 566.927 ns/op
GetCallerClass.exception_Throwable_getStackTrace_v4 avgt 5 49530.699 ± 773.626 ns/op
GetCallerClass.invokeHandle_Throwable_getStackTraceElement avgt 5 1738.658 ± 21.474 ns/op
GetCallerClass.invokeMethod_Throwable_getStackTraceElement avgt 5 1633.620 ± 33.011 ns/op
GetCallerClass.static_Reflection_getCallerClass avgt 5 313.214 ± 5.901 ns/op
Here’s a gist with the source code for this benchmark: GetCallerClass.java at https://gist.github.com/anonymous/8777ffbfd3a39c1a3f61eb4d64711c8f
What really surprised me was how well Reflection.getCallerClass performs compared to my earlier new Throwable().getStackTrace() versions, which are quite abysmal. So I’m curious to see how its replacement is going to do.
Feel free to adapt and use the benchmark as you want.
Sent from Mail for Windows 10
From: Ralph Goers
Sent: Tuesday, March 14, 2017 07:04
To: Mandy Chung
Subject: Re: Review request 8153912: StackFrame::getFileName andStackFrame::getLineNumber not needed
I have fixed the test that located the caller’s Class object with StackWalker. It is now faster than Reflection.getCallerClass() was.
I have also created a test to get the Caller’s StackTraceElement with StackWalker. It is now much, much faster than walking the Throwable was in Java 8, so that will be a definite incentive for Log4j to use it.
Sorry for the misinformation on these but thanks for giving me help on improving the tests.
> On Mar 13, 2017, at 3:38 PM, Mandy Chung <mandy.chung at oracle.com> wrote:
> Hi Ralph,
> I have filed https://bugs.openjdk.java.net/browse/JDK-8176593 <https://bugs.openjdk.java.net/browse/JDK-8176593> for Throwable::getStackTrace performance regression.
>> On Mar 13, 2017, at 1:57 PM, Daniel Fuchs <daniel.fuchs at oracle.com> wrote:
>> Hi Ralph,
>> On 13/03/17 19:06, Ralph Goers wrote:
>>> OK - I will do that when I fix the other bug. But if you can suggest some other way to bail out of the loop after I have found the correct StackFrame that would help as well.
>> I'd suggest using filter + findFirst, possibly with a
>> statefull Predicate<StackFrame> - depending on the logic
>> needed to identify the frame you want to return.
>> That's what we do in java.util.logging - where we walk
>> until we find a logger implementation frame, and then
>> continue walking until we find a frame that no longer
>> belong to the logging infrastructure.
> As Daniel said, we suggest to walk the stack from the most recent frame and stops when the logging implementation frames are skipped.
> This is where java.util.logging does its filtering that you can reference:
> http://hg.openjdk.java.net/jdk9/jdk9/jdk/file/ddf8af0e536a/src/java.logging/share/classes/java/util/logging/LogRecord.java#l696 <http://hg.openjdk.java.net/jdk9/jdk9/jdk/file/ddf8af0e536a/src/java.logging/share/classes/java/util/logging/LogRecord.java#l696>
More information about the core-libs-dev