fast way to infer caller

[Remi Forax]

----- Original Message -----
> From: "Ceki Gülcü" <ceki at qos.ch>
> To: "core-libs-dev" <core-libs-dev at openjdk.java.net>
> Sent: Wednesday, April 6, 2022 11:26:39 PM
> Subject: Re: fast way to infer caller

> Hi Rémi,
> 
> Thank you for your answer.
> 
> According to some benchmarks on a i7-8565U Intel CPU (quite average
> CPU), here are the costs of computing the caller class via different
> methods:
> 
> using new Throwable().getStackTrace: 11 microseconds per call
> using StackWalker API: 1.8 microseconds per call
> using SecurityManager: 0.9 microseconds per call
> 
> While a six fold improvement (StackWalker compared to new Throwable) is
> nothing to sneeze at, the performance of StackWalker is not as good as
> with a custom SecurityManager.
> 
> I have not said so explicitly but the aim here is to allow the user to
> obtain a new logger by calling LoggerFactory.getLogger() with no
> arguments with the returned logger named after the caller class.
> 
> Spending 1 or 2 microseconds for this call is OK if the logger is a
> static field. However, if the logger is an instance field, then spending
> 2 microseconds per host object instance just to obtain a logger might
> have a noticeable impact on performance. It follows that the performance
> of LoggerFactory.getLogger() must be exceptionally good, assuming we
> wish to avoid having the user accidentally shooting herself on the foot,
> ergo the 100 nanosecond performance per call requirement.
> 
> Noting that invoking MethodHandles.lookup().lookupClass() seems very
> fast (about 2 nanoseconds), I would be very interested if  new
> lookup(int index) method were added to java.lang.invoke.MethodHandles
> class, with index designating the desired index on the call stack.
> 
> Does the above make sense? How difficult would it be to add such a method ?

I think that for MethodHandles.lookup() and all other caller sensitive methods, the VM uses a trick, it inlines the call into the caller method, once this is done, the caller class is know statically and can be replaced by a constant. In order to use the same trick, you need a way to force the inlining through getLogger(), the is something the JDK can do but that is not available to user code.

And you do not want lookup(-1) because getLogger() can be called by reflection, java.lang.invoke or a lambda, in all these cases you have "hidden" stack frames in between the user code code and LoggerFactory.getLogger(), you need to skip those stack frames, this is what the StackWalker does.

Now, i don't think there is a real solution to you issue, worst i will try to convince you that this is not a real problem :)
You are offering convenience using magic to your user, this has a cost.

For me this is very similar to the trade off you have by offering to change the logger configuration at runtime.
This is convenient but it requires a volatile read (even when the logger is de-activated) which destroy performance in tight loop (you loose hoisting).
I believe that if your users are fine with that, they are also fine with a call to LoggerFactory.getLogger() being a little slow.

> 
> --
> Ceki Gülcü

Rémi

> 
> 
> On 4/6/2022 5:52 PM, Remi Forax wrote:
>> ----- Original Message -----
>>> From: "Ceki Gülcü" <ceki at qos.ch>
>>> To: "core-libs-dev" <core-libs-dev at openjdk.java.net>
>>> Sent: Wednesday, April 6, 2022 5:30:51 PM
>>> Subject: fast way to infer caller
>> 
>>> Hello,
>> 
>> Hello,
>> 
>>>
>>> As you are probably aware, one of the important primitives used in
>>> logging libraries is inferring the caller of a given logging statement.
>>> The current common practice is to create a throwable and process its
>>> stack trace. This is rather wasteful and rather slow. As an alternative,
>>> I have tried using the StackWalker API to infer the caller but was
>>> unsatisfied with the performance.
>>>
>>> MethodHandles.lookup().lookupClass() looks very promising except that
>>> there is no way to specify the depth.
>>>
>>> I am looking for a method to obtain the Nth caller at a cost of around
>>> 100 to 200 nanoseconds of CPU time.  Do you think the JDK could cater
>>> for this use case?
>> 
>> We have designed the StackWalker with that in mind
>> https://docs.oracle.com/en/java/javase/17/docs/api/java.base/java/lang/StackWalker.html
>> 
>> see the discussion on StackWalker.getCallerClass()
>> https://docs.oracle.com/en/java/javase/17/docs/api/java.base/java/lang/StackWalker.html#getCallerClass()