Review request 8153912: StackFrame::getFileName andStackFrame::getLineNumber not needed

[Timo Kinnunen]

Hi, 

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
Cc: core-libs-dev
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.

Ralph

> 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>
> 
> Mandy