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 > On Apr 13, 2016, at 12:03 PM, Mandy Chung <mandy.ch...@oracle.com> wrote: > > If you record all stack frames, I can believe Throwable is faster because of > a recent optimization JDK-8150778 that has been made in jdk9 to improve the > Throwable::getStackTraceElements method. > > Mandy > >> On Apr 13, 2016, at 11:49 AM, Ralph Goers <ralph.go...@dslextreme.com> wrote: >> >> I did a raw test of StackWalker by itself and the performance was much >> better than using a Throwable to get the location information. However, I >> haven’t tested how it will be implemented in Log4j. We still support Java 7 >> (and will for some time) so we have to find a way to support using >> StackWalker when running on Java 9 even though we build with Java 7. >> >> Ralph >> >>> On Apr 13, 2016, at 10:27 AM, Mandy Chung <mandy.ch...@oracle.com> wrote: >>> >>> It is good to know Log4J is planning to use StackWalker. >>> >>> Thanks for the feedback. I will reconsider. >>> >>> One thing to mention is the patch went in jdk9/hs-rt that will show up in >>> jdk9/dev some time that changes the implementation to create >>> StackTraceElement to get filename and line number. The object allocation >>> should be cheap that does create short-lived objects. The main motivation >>> of JDK-8153123 was to simplify the hotspot implementation that the runtime >>> team had concern about. There is an open issue to follow up the performance >>> (JDK-8153683). It’d be helpful to get your feedback on using StackWalker >>> API and the performance data. >>> >>> Mandy >>> >>>> On Apr 13, 2016, at 6:51 AM, Ralph Goers <ralph.go...@dslextreme.com> >>>> wrote: >>>> >>>> I had planned on using StackWalker to generate the location information >>>> for every logging event. It seems that this change would thus cause the >>>> creation of a new StackTraceElement for every logger event. That seems >>>> wasteful. Log4j is currently in the process of trying to reduce the number >>>> of objects that are created while logging as it has a significant impact >>>> on garbage collection. So I am also in favor of getting the filename and >>>> line number directly from the StackFrame. >>>> >>>> Ralph >>>> >>>>> On Apr 12, 2016, at 5:15 PM, Mandy Chung <mandy.ch...@oracle.com> wrote: >>>>> >>>>> >>>>>> On Apr 12, 2016, at 1:34 AM, Rémi Forax <fo...@univ-mlv.fr> wrote: >>>>>> >>>>>> Hi Mandy, >>>>>> I really don't like this patch. >>>>>> >>>>>> Being forced to call toStackElement to get the line number is counter >>>>>> intuitive. >>>>>> I would prefer the two methods to not return Optional but an int and a >>>>>> String with the same convention as StackElement if the point of this >>>>>> patch is to remove the dependency to Optional. >>>>>> >>>>> >>>>> I was expecting the common usage of StackWalker API does not need file >>>>> name and line number. I think it'd be useful to include >>>>> StackFrame::getBci (in the future it might include live information like >>>>> locals etc) and keep the optional stuff and uncommon usage to >>>>> StackTraceElement. >>>>> >>>>> Mandy >>>>> >>>>> >>>>>> Rémi >>>>>> >>>>>> >>>>>> Le 11 avril 2016 23:22:39 CEST, Mandy Chung <mandy.ch...@oracle.com> a >>>>>> écrit : >>>>>>> Webrev at: >>>>>>> http://cr.openjdk.java.net/~mchung/jdk9/webrevs/8153912/webrev.00/index.html >>>>>>> >>>>>>> StackFrame::getFileName and StackFrame::getLineNumber are originally >>>>>>> proposed with the view of any stack walking code can migrate to the >>>>>>> StackWalker API without the use of StackTraceElement. >>>>>>> >>>>>>> File name and line number are useful for debugging and troubleshooting >>>>>>> purpose. It has additional overhead to map from a method and BCI to >>>>>>> look up the file name and line number. >>>>>>> >>>>>>> StackFrame::toStackTraceElement method returns StackTraceElement that >>>>>>> includes the file name and line number. There is no particular benefit >>>>>>> to duplicate getFileName and getLineNumber methods in StackFrame. It is >>>>>>> equivalently convenient to call >>>>>>> StackFrame.toStackTraceElement().getFileName() (or getLineNumber). >>>>>>> >>>>>>> This patch proposes to remove StackFrame::getFileName and >>>>>>> StackFrame::getLineNumber methods since such information can be >>>>>>> obtained from StackFrame.toStackTraceElement(). >>>>>>> >>>>>>> Mandy >>>>>> >>>>> >>>>> >>>> >>>> >>> >>> >> >> > >
