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

[Ralph Goers]

> On Mar 13, 2017, at 11:54 AM, Ralph Goers <ralph.goers at dslextreme.com> wrote:
> 
> 
>> On Mar 13, 2017, at 11:52 AM, Ralph Goers <ralph.goers at dslextreme.com> wrote:
>> 
>>> 
>>> On Mar 13, 2017, at 11:32 AM, Daniel Fuchs <daniel.fuchs at oracle.com> wrote:
>>> 
>>> Hi Ralph,
>>> 
>>> On 13/03/2017 04:25, Ralph Goers wrote:
>>>> Sorry for not getting back sooner but I finally found some time to follow up.
>>>> 
>>>> I took a look at https://www.sitepoint.com/deep-dive-into-java-9s-stack-walking-api/ <https://www.sitepoint.com/deep-dive-into-java-9s-stack-walking-api/> and modified the benchmarks that were used there to add a few more use cases. I also created a small set of benchmarks for Java 8 to compare it against.  The resulting project is at https://github.com/rgoers/stackwalker-vs-Reflection_getCallerClass/tree/master/java9 <https://github.com/rgoers/stackwalker-vs-Reflection_getCallerClass/tree/master/java9>.  I’ve summarized the results in https://issues.apache.org/jira/browse/LOG4J2-1359 <https://issues.apache.org/jira/browse/LOG4J2-1359>, but for your convenience here are the bullet points:
>>>> 
>>>> 1. Walking the Throwable StackTraceElements is significantly faster in Java 8 than Java 9. I am not sure what benchmark Brent used but my results differ.
>>>> 2. Using StackWalker to get the StackTraceElements in Java 9 is almost twice as slow as walking the Throwable in Java 8. (Log4j relied on this pre-Java9 and apparently will have to continue to do so, but it will now be slower).
>>>> 3. Using StackWalker to search for the caller's class is about twice as slow as sun.reflect.Reflection.getCallerClass() was (Log4j requires this and it is going to hurt performance).
>>>> 4. sun.reflect.Reflection.getCallerClass is about 10 times faster than using StackWalker.getCallerClass to obtain the Class object of the immediate caller.
>>>> In short it appears that the performance of StackWalker means that we are going to want to avoid using it.
>>>> 
>>>> Ralph
>>> 
>>> StackWalker can give you some performance improvements if
>>> you walk the stack from i=0 to i=StackTraceElements[].length,
>>> and stop somewhere before reaching the end.
>>> 
>>> If you attempt to walk the stack backwards, starting from
>>> i=StackTraceElements[].length and decreasing i, then I would
>>> not expect as much improvement as you will need to walk the
>>> whole stack anyway.
>>> 
>>> best regards,
>>> 
>>> — daniel
>> 
>> The “search” that uses StackWalker probably walks it to the end because I had to use test() to determine the StackFrame to return. If you can provide a better algorithm to use I’d be happy to retest it. If I=0 is the current StackFrame, then that is what we do. Please take a look at the stackwalkerSearch method at https://github.com/rgoers/stackwalker-vs-Reflection_getCallerClass/blob/master/java9/src/main/java/org/github/arnaudroger/StackWalkerGetCallerClass.java <https://github.com/rgoers/stackwalker-vs-Reflection_getCallerClass/blob/master/java9/src/main/java/org/github/arnaudroger/StackWalkerGetCallerClass.java> <https://github.com/rgoers/stackwalker-vs-Reflection_getCallerClass/blob/master/java9/src/main/java/org/github/arnaudroger/StackWalkerGetCallerClass.java <https://github.com/rgoers/stackwalker-vs-Reflection_getCallerClass/blob/master/java9/src/main/java/org/github/arnaudroger/StackWalkerGetCallerClass.java>>.
>> 
>> Ralph
> 
> Sorry - it uses the reduce method, not test.
> 
> Ralph

And in looking over that code again it doesn’t look right to me. I will have to fix it.  Still, it is going to end up walking the whole stack.

Ralph

> 
>> 
>> 
>> 
>>> 
>>>> 
>>>> 
>>>> 
>>>>> On May 18, 2016, at 11:24 AM, Brent Christian <brent.christian at oracle.com> wrote:
>>>>> 
>>>>> Hi,
>>>>> 
>>>>> I compared 8u65 and 9b116 performance on a simple Throwable.getStackTrace() JMH benchmark that I have, using a variety of call stack depths.  Performance looks very similar between the two; if anything, 9b116 has a slight edge for larger stack depths.
>>>>> 
>>>>> So I don't think the difference is due to the walking of the stack itself, at least based on what I measured.
>>>>> 
>>>>> HTH,
>>>>> -Brent
>>>>> 
>>>>> On 5/10/16 9:49 AM, Ralph Goers wrote:
>>>>>> I just ran one of the Log4j performance tests that specifically captures location information.  To run the test I do
>>>>>> 
>>>>>> java -jar log4j-perf/target/benchmarks.jar ".*AsyncAppenderLog4j2LocationBenchmark.*" -f 1 -wi 10 -i 20 -t 4 -si true
>>>>>> 
>>>>>> And the results are:
>>>>>> 
>>>>>> java version "1.7.0_80
>>>>>> 
>>>>>> Benchmark                                                             Mode  Samples       Score      Error  Units
>>>>>> o.a.l.l.p.j.AsyncAppenderLog4j2LocationBenchmark.throughputSimple    thrpt       20  124819.285 ± 3003.918  ops/s
>>>>>> 
>>>>>> java version "1.8.0_65"
>>>>>> 
>>>>>> Benchmark                                                             Mode  Samples       Score      Error  Units
>>>>>> o.a.l.l.p.j.AsyncAppenderLog4j2LocationBenchmark.throughputSimple    thrpt       20  123209.746 ± 3064.672  ops/s
>>>>>> 
>>>>>> 
>>>>>> java version "9-ea"
>>>>>> Java(TM) SE Runtime Environment (build 9-ea+116)
>>>>>> 
>>>>>> Benchmark                                                             Mode  Samples      Score      Error  Units
>>>>>> o.a.l.l.p.j.AsyncAppenderLog4j2LocationBenchmark.throughputSimple    thrpt       20  96090.261 ± 4565.763  ops/s
>>>>>> 
>>>>>> 
>>>>>> This tells me that Java 9 is about 23% slower than previous versions in walking the stack trace elements.
>>>>>> 
>>>>>> Ralph
> 
>