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

classic Classic list List threaded Threaded
46 messages Options
123
Reply | Threaded
Open this post in threaded view
|

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

Mandy Chung
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
Reply | Threaded
Open this post in threaded view
|

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

Remi Forax
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.

Rémi


Le 11 avril 2016 23:22:39 CEST, Mandy Chung <[hidden email]> 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

Reply | Threaded
Open this post in threaded view
|

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

Mandy Chung

> On Apr 12, 2016, at 1:34 AM, Rémi Forax <[hidden email]> 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 <[hidden email]> 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
>

Reply | Threaded
Open this post in threaded view
|

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

Ralph Goers
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 <[hidden email]> wrote:
>
>
>> On Apr 12, 2016, at 1:34 AM, Rémi Forax <[hidden email]> 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 <[hidden email]> 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
>>
>
>


Reply | Threaded
Open this post in threaded view
|

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

Mandy Chung
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 <[hidden email]> 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 <[hidden email]> wrote:
>>
>>
>>> On Apr 12, 2016, at 1:34 AM, Rémi Forax <[hidden email]> 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 <[hidden email]> 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
>>>
>>
>>
>
>

Reply | Threaded
Open this post in threaded view
|

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

Ralph Goers
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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> wrote:
>>>
>>>
>>>> On Apr 12, 2016, at 1:34 AM, Rémi Forax <[hidden email]> 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 <[hidden email]> 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
>>>>
>>>
>>>
>>
>>
>
>


Reply | Threaded
Open this post in threaded view
|

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

Mandy Chung
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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> wrote:
>>>>
>>>>
>>>>> On Apr 12, 2016, at 1:34 AM, Rémi Forax <[hidden email]> 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 <[hidden email]> 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
>>>>>
>>>>
>>>>
>>>
>>>
>>
>>
>
>

Reply | Threaded
Open this post in threaded view
|

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

Mandy Chung
In reply to this post by Mandy Chung
Updated webrev:
   http://cr.openjdk.java.net/~mchung/jdk9/webrevs/8153912/webrev.01/index.html

I added a new StackFrame::getByteCodeIndex method to return bci and updatedgetFileName and getLineNumber to have the same returned type as in StackTraceElement.  From usage perspective, the caller has to prepare and handle the information is unavailable and I think it would typically log some token to represent the unavailable case and might well use null and negative value. This patch would save the creation of short-lived Optional object that might help logging filename/linenumber case.

I’m working on a new test to verify bci and line number to be included in the next revision.

Mandy

> On Apr 11, 2016, at 2:22 PM, Mandy Chung <[hidden email]> wrote:
>
> 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

Reply | Threaded
Open this post in threaded view
|

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

Brent Christian-2
Hi, Mandy

It looks good to me.  A few minor things:

StackFrameInfo.java:

Should getByteCodeIndex() be final ?


StackWalker.java, line 136:
* change ';' to ','


JavaLangInvokeAccess.java, line 40:

For the isNative() docs, I would prefer "Returns true if..." to "Tests
if..."


Some test code for getByteCodeIndex() would be good - sounds like you
plan to add that.

Thanks,
-Brent
On 04/27/2016 11:31 AM, Mandy Chung wrote:

> Updated webrev:
>     http://cr.openjdk.java.net/~mchung/jdk9/webrevs/8153912/webrev.01/index.html
>
> I added a new StackFrame::getByteCodeIndex method to return bci and updatedgetFileName and getLineNumber to have the same returned type as in StackTraceElement.  From usage perspective, the caller has to prepare and handle the information is unavailable and I think it would typically log some token to represent the unavailable case and might well use null and negative value. This patch would save the creation of short-lived Optional object that might help logging filename/linenumber case.
>
> I’m working on a new test to verify bci and line number to be included in the next revision.
>
> Mandy
>
>> On Apr 11, 2016, at 2:22 PM, Mandy Chung <[hidden email]> wrote:
>>
>> 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
>

Reply | Threaded
Open this post in threaded view
|

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

Mandy Chung

> On Apr 28, 2016, at 11:37 AM, Brent Christian <[hidden email]> wrote:
>
> Hi, Mandy
>
> It looks good to me.  A few minor things:
>
> StackFrameInfo.java:
>
> Should getByteCodeIndex() be final ?
>

It’s a package-private class and so no subclass outside this package anyway.  So it doesn’t really matter. I didn’t catch the inconsistency there - some methods in this class are final and some are not. I may clean them up.


>
> StackWalker.java, line 136:
> * change ';' to ‘,'
>

ok.

>
> JavaLangInvokeAccess.java, line 40:
>
> For the isNative() docs, I would prefer "Returns true if..." to "Tests if..."
>
>

Both conventions are used.  I can change that.

> Some test code for getByteCodeIndex() would be good - sounds like you plan to add that.

yes.  Will send out for review next.

thanks for the review.
Mandy

>
> Thanks,
> -Brent
> On 04/27/2016 11:31 AM, Mandy Chung wrote:
>> Updated webrev:
>>    http://cr.openjdk.java.net/~mchung/jdk9/webrevs/8153912/webrev.01/index.html
>>
>> I added a new StackFrame::getByteCodeIndex method to return bci and updatedgetFileName and getLineNumber to have the same returned type as in StackTraceElement.  From usage perspective, the caller has to prepare and handle the information is unavailable and I think it would typically log some token to represent the unavailable case and might well use null and negative value. This patch would save the creation of short-lived Optional object that might help logging filename/linenumber case.
>>
>> I’m working on a new test to verify bci and line number to be included in the next revision.
>>
>> Mandy
>>
>>> On Apr 11, 2016, at 2:22 PM, Mandy Chung <[hidden email]> wrote:
>>>
>>> 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
>>
>

Reply | Threaded
Open this post in threaded view
|

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

Daniel Fuchs
Hi Mandy,

This looks good to me.

Regarding final methods, I believe it might be prudent
to make toStackTraceElement() final - and possibly also
all the getters that call it.

It would be imprudent to try to override any of these
methods in a subclass without looking at the implementation
in the superclass. Making these methods final will ensure
that future maintainers will at least need to look at
the implementation in StackFrameInfo before they
override any of them.

best regards,

-- daniel


On 28/04/16 21:42, Mandy Chung wrote:

>
>> On Apr 28, 2016, at 11:37 AM, Brent Christian <[hidden email]> wrote:
>>
>> Hi, Mandy
>>
>> It looks good to me.  A few minor things:
>>
>> StackFrameInfo.java:
>>
>> Should getByteCodeIndex() be final ?
>>
>
> It’s a package-private class and so no subclass outside this package anyway.  So it doesn’t really matter. I didn’t catch the inconsistency there - some methods in this class are final and some are not. I may clean them up.
>
>
>>
>> StackWalker.java, line 136:
>> * change ';' to ‘,'
>>
>
> ok.
>
>>
>> JavaLangInvokeAccess.java, line 40:
>>
>> For the isNative() docs, I would prefer "Returns true if..." to "Tests if..."
>>
>>
>
> Both conventions are used.  I can change that.
>
>> Some test code for getByteCodeIndex() would be good - sounds like you plan to add that.
>
> yes.  Will send out for review next.
>
> thanks for the review.
> Mandy
>
>>
>> Thanks,
>> -Brent
>> On 04/27/2016 11:31 AM, Mandy Chung wrote:
>>> Updated webrev:
>>>    http://cr.openjdk.java.net/~mchung/jdk9/webrevs/8153912/webrev.01/index.html
>>>
>>> I added a new StackFrame::getByteCodeIndex method to return bci and updatedgetFileName and getLineNumber to have the same returned type as in StackTraceElement.  From usage perspective, the caller has to prepare and handle the information is unavailable and I think it would typically log some token to represent the unavailable case and might well use null and negative value. This patch would save the creation of short-lived Optional object that might help logging filename/linenumber case.
>>>
>>> I’m working on a new test to verify bci and line number to be included in the next revision.
>>>
>>> Mandy
>>>
>>>> On Apr 11, 2016, at 2:22 PM, Mandy Chung <[hidden email]> wrote:
>>>>
>>>> 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
>>>
>>
>

Reply | Threaded
Open this post in threaded view
|

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

Mandy Chung
This version includes a new test:
  http://cr.openjdk.java.net/~mchung/jdk9/webrevs/8153912/webrev.02/

Daniel - StackFrameInfo class is package-private class  In the future this may become a final class once we decide what to do with locals and operands in a future release.  I don’t worry about someone else overriding the implementation.

Mandy
Reply | Threaded
Open this post in threaded view
|

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

Brent Christian-2
The new test looks good, Mandy.

Thanks,
-Brent
On 05/04/2016 12:36 PM, Mandy Chung wrote:
> This version includes a new test:
>    http://cr.openjdk.java.net/~mchung/jdk9/webrevs/8153912/webrev.02/
>
> Daniel - StackFrameInfo class is package-private class  In the future this may become a final class once we decide what to do with locals and operands in a future release.  I don’t worry about someone else overriding the implementation.
>
> Mandy
>

Reply | Threaded
Open this post in threaded view
|

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

Ralph Goers
In reply to this post by Mandy Chung
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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> wrote:
>>>>>
>>>>>
>>>>>> On Apr 12, 2016, at 1:34 AM, Rémi Forax <[hidden email]> 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 <[hidden email]> 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
>>>>>>
>>>>>
>>>>>
>>>>
>>>>
>>>
>>>
>>
>>
>
>

Reply | Threaded
Open this post in threaded view
|

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

Mandy Chung
What does your benchmark call?

Mandy

> On May 10, 2016, at 9:49 AM, Ralph Goers <[hidden email]> 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
>
>> On Apr 13, 2016, at 12:03 PM, Mandy Chung <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> wrote:
>>>>>>
>>>>>>
>>>>>>> On Apr 12, 2016, at 1:34 AM, Rémi Forax <[hidden email]> 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 <[hidden email]> 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
>>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>
>>>>
>>>
>>>
>>
>>
>

Reply | Threaded
Open this post in threaded view
|

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

Ralph Goers
The benchmark logs events using Log4j 2’s asynchronous loggers. In the process of doing that it captures the location information using the code below:


// LOG4J2-1029 new Throwable().getStackTrace is faster than Thread.currentThread().getStackTrace().
final StackTraceElement[] stackTrace = new Throwable().getStackTrace();
StackTraceElement last = null;
for (int i = stackTrace.length - 1; i > 0; i--) {
    final String className = stackTrace[i].getClassName();
    if (fqcnOfLogger.equals(className)) {
        return last;
    }
    last = stackTrace[i];
}
return null;

Ralph


> On May 10, 2016, at 9:57 AM, Mandy Chung <[hidden email]> wrote:
>
> What does your benchmark call?
>
> Mandy
>
>> On May 10, 2016, at 9:49 AM, Ralph Goers <[hidden email]> 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
>>
>>> On Apr 13, 2016, at 12:03 PM, Mandy Chung <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> wrote:
>>>>>>>
>>>>>>>
>>>>>>>> On Apr 12, 2016, at 1:34 AM, Rémi Forax <[hidden email]> 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 <[hidden email]> 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
>>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>
>>>>
>>>
>>>
>>
>
>

Reply | Threaded
Open this post in threaded view
|

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

Mandy Chung
This walks the stack to find a frame with a matching class.  Throwable::getStackTrace is taking the entire stack trace.  I suggest to try StackWalker and avoids the overhead of dumping the entire stack trace.

Mandy

> On May 10, 2016, at 10:40 AM, Ralph Goers <[hidden email]> wrote:
>
> The benchmark logs events using Log4j 2’s asynchronous loggers. In the process of doing that it captures the location information using the code below:
>
>
> // LOG4J2-1029 new Throwable().getStackTrace is faster than Thread.currentThread().getStackTrace().
> final StackTraceElement[] stackTrace = new Throwable().getStackTrace();
> StackTraceElement last = null;
> for (int i = stackTrace.length - 1; i > 0; i--) {
>     final String className = stackTrace[i].getClassName();
>     if (fqcnOfLogger.equals(className)) {
>         return last;
>     }
>     last = stackTrace[i];
> }
> return null;
>
> Ralph
>
>
>> On May 10, 2016, at 9:57 AM, Mandy Chung <[hidden email]> wrote:
>>
>> What does your benchmark call?
>>
>> Mandy
>>
>>> On May 10, 2016, at 9:49 AM, Ralph Goers <[hidden email]> 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
>>>
>>>> On Apr 13, 2016, at 12:03 PM, Mandy Chung <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> wrote:
>>>>>>>>
>>>>>>>>
>>>>>>>>> On Apr 12, 2016, at 1:34 AM, Rémi Forax <[hidden email]> 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 <[hidden email]> 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
>>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>
>>>>
>>>
>>
>>
>

Reply | Threaded
Open this post in threaded view
|

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

Ralph Goers
OK - I try that. My  earlier comparison had shown that StackWalker was much faster but since walking the Throwable is so much slower I’m now wondering how much better than Java 7 & 8 it will be.

Any idea why walking the Throwable is so much slower?

Ralph

> On May 10, 2016, at 5:01 PM, Mandy Chung <[hidden email]> wrote:
>
> This walks the stack to find a frame with a matching class.  Throwable::getStackTrace is taking the entire stack trace.  I suggest to try StackWalker and avoids the overhead of dumping the entire stack trace.
>
> Mandy
>
>> On May 10, 2016, at 10:40 AM, Ralph Goers <[hidden email]> wrote:
>>
>> The benchmark logs events using Log4j 2’s asynchronous loggers. In the process of doing that it captures the location information using the code below:
>>
>>
>> // LOG4J2-1029 new Throwable().getStackTrace is faster than Thread.currentThread().getStackTrace().
>> final StackTraceElement[] stackTrace = new Throwable().getStackTrace();
>> StackTraceElement last = null;
>> for (int i = stackTrace.length - 1; i > 0; i--) {
>>    final String className = stackTrace[i].getClassName();
>>    if (fqcnOfLogger.equals(className)) {
>>        return last;
>>    }
>>    last = stackTrace[i];
>> }
>> return null;
>>
>> Ralph
>>
>>
>>> On May 10, 2016, at 9:57 AM, Mandy Chung <[hidden email]> wrote:
>>>
>>> What does your benchmark call?
>>>
>>> Mandy
>>>
>>>> On May 10, 2016, at 9:49 AM, Ralph Goers <[hidden email]> 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
>>>>
>>>>> On Apr 13, 2016, at 12:03 PM, Mandy Chung <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> wrote:
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>> On Apr 12, 2016, at 1:34 AM, Rémi Forax <[hidden email]> 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 <[hidden email]> 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
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>
>>>
>>>
>>
>
>


Reply | Threaded
Open this post in threaded view
|

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

Mandy Chung

> On May 10, 2016, at 5:17 PM, Ralph Goers <[hidden email]> wrote:
>
> OK - I try that. My  earlier comparison had shown that StackWalker was much faster but since walking the Throwable is so much slower I’m now wondering how much better than Java 7 & 8 it will be.
>
> Any idea why walking the Throwable is so much slower?
>

No idea yet.  Can you share your benchmark so that we can understand what you measure?  

Mandy

> Ralph
>
>> On May 10, 2016, at 5:01 PM, Mandy Chung <[hidden email]> wrote:
>>
>> This walks the stack to find a frame with a matching class.  Throwable::getStackTrace is taking the entire stack trace.  I suggest to try StackWalker and avoids the overhead of dumping the entire stack trace.
>>
>> Mandy
>>
>>> On May 10, 2016, at 10:40 AM, Ralph Goers <[hidden email]> wrote:
>>>
>>> The benchmark logs events using Log4j 2’s asynchronous loggers. In the process of doing that it captures the location information using the code below:
>>>
>>>
>>> // LOG4J2-1029 new Throwable().getStackTrace is faster than Thread.currentThread().getStackTrace().
>>> final StackTraceElement[] stackTrace = new Throwable().getStackTrace();
>>> StackTraceElement last = null;
>>> for (int i = stackTrace.length - 1; i > 0; i--) {
>>>   final String className = stackTrace[i].getClassName();
>>>   if (fqcnOfLogger.equals(className)) {
>>>       return last;
>>>   }
>>>   last = stackTrace[i];
>>> }
>>> return null;
>>>
>>> Ralph
>>>
>>>
>>>> On May 10, 2016, at 9:57 AM, Mandy Chung <[hidden email]> wrote:
>>>>
>>>> What does your benchmark call?
>>>>
>>>> Mandy
>>>>
>>>>> On May 10, 2016, at 9:49 AM, Ralph Goers <[hidden email]> 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
>>>>>
>>>>>> On Apr 13, 2016, at 12:03 PM, Mandy Chung <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> wrote:
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>> On Apr 12, 2016, at 1:34 AM, Rémi Forax <[hidden email]> 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 <[hidden email]> 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
>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>
>>>>>>
>>>>>
>>>>
>>>>
>>>
>>
>>
>
>

Reply | Threaded
Open this post in threaded view
|

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

Ralph Goers
Here is the link to the source - https://git-wip-us.apache.org/repos/asf?p=logging-log4j2.git;a=blob;f=log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/AsyncAppenderLog4j2LocationBenchmark.java;h=c306ac1a0f475d772b6ccb8afa527dc037d7c646;hb=HEAD <https://git-wip-us.apache.org/repos/asf?p=logging-log4j2.git;a=blob;f=log4j-perf/src/main/java/org/apache/logging/log4j/perf/jmh/AsyncAppenderLog4j2LocationBenchmark.java;h=c306ac1a0f475d772b6ccb8afa527dc037d7c646;hb=HEAD>. You can check out all of Log4j 2 by doing

git clone http://git-wip-us.apache.org/repos/asf/logging-log4j2.git

Ralph



> On May 10, 2016, at 7:26 PM, Mandy Chung <[hidden email]> wrote:
>
>
>> On May 10, 2016, at 5:17 PM, Ralph Goers <[hidden email]> wrote:
>>
>> OK - I try that. My  earlier comparison had shown that StackWalker was much faster but since walking the Throwable is so much slower I’m now wondering how much better than Java 7 & 8 it will be.
>>
>> Any idea why walking the Throwable is so much slower?
>>
>
> No idea yet.  Can you share your benchmark so that we can understand what you measure?  
>
> Mandy
>
>> Ralph
>>
>>> On May 10, 2016, at 5:01 PM, Mandy Chung <[hidden email]> wrote:
>>>
>>> This walks the stack to find a frame with a matching class.  Throwable::getStackTrace is taking the entire stack trace.  I suggest to try StackWalker and avoids the overhead of dumping the entire stack trace.
>>>
>>> Mandy
>>>
>>>> On May 10, 2016, at 10:40 AM, Ralph Goers <[hidden email]> wrote:
>>>>
>>>> The benchmark logs events using Log4j 2’s asynchronous loggers. In the process of doing that it captures the location information using the code below:
>>>>
>>>>
>>>> // LOG4J2-1029 new Throwable().getStackTrace is faster than Thread.currentThread().getStackTrace().
>>>> final StackTraceElement[] stackTrace = new Throwable().getStackTrace();
>>>> StackTraceElement last = null;
>>>> for (int i = stackTrace.length - 1; i > 0; i--) {
>>>>  final String className = stackTrace[i].getClassName();
>>>>  if (fqcnOfLogger.equals(className)) {
>>>>      return last;
>>>>  }
>>>>  last = stackTrace[i];
>>>> }
>>>> return null;
>>>>
>>>> Ralph
>>>>
>>>>
>>>>> On May 10, 2016, at 9:57 AM, Mandy Chung <[hidden email]> wrote:
>>>>>
>>>>> What does your benchmark call?
>>>>>
>>>>> Mandy
>>>>>
>>>>>> On May 10, 2016, at 9:49 AM, Ralph Goers <[hidden email]> 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
>>>>>>
>>>>>>> On Apr 13, 2016, at 12:03 PM, Mandy Chung <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> 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 <[hidden email]> wrote:
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>> On Apr 12, 2016, at 1:34 AM, Rémi Forax <[hidden email]> 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 <[hidden email]> 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
>>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>
>>>
>>>
>>
>>
>
>

123