Separate logging for JPMS module/layer

[Ralph Goers]

> On Oct 5, 2018, at 10:54 AM, David Lloyd <david.lloyd at redhat.com> wrote:
> 
> On Fri, Oct 5, 2018 at 10:12 AM Ralph Goers <rgoers at apache.org> wrote:
>>> On Oct 5, 2018, at 1:10 AM, Luke Hutchison <luke.hutch at gmail.com> wrote:
>>> 
>>> On Thu, Oct 4, 2018, 10:27 PM Ralph Goers <rgoers at apache.org <mailto:rgoers at apache.org>> wrote:
>>> Yes, we have found in some situations using the SecurityManager is faster than StackWalker.
>>> 
>>> This is interesting -- how much slower is StackWalker in these situations, and under what condition is there a speed difference?
>> 
>> Benchmark Mode Cnt Score Error Units
>> StackTraceBenchmark.defaultJava8 thrpt 3 113965.921 ± 119706.986 ops/s
>> StackTraceBenchmark.securityManager thrpt 3 788004.237 ± 82578.567 ops/s
>> StackTraceBenchmark.stackWalker thrpt 3 182902.031 ± 39018.395 ops/s
> 
> Something to consider is _how_ the StackWalker is used.  It's
> potentially quite expensive in that it produces a Stream in its full
> usage mode.  Have you compared using the stream + lambda approach
> versus extracting the stream iterator and iterating in the classic
> Java fashion?  I doubt it would make the benchmark competitive, but it
> might help a little bit.
> 
> In the end, StackWalker does a relatively large amount of work and
> performs substantially more object allocations than the simpler
> classical approaches.  Extracting any decent performance of
> StackWalker would probably be highly contingent on successful compiler
> optimizations like devirtualizing and inlining the stream processing,
> deleting unused allocations, etc.  In practice these kinds of
> optimizations seem very finicky and quite easy to inadvertently
> defeat, which is why I've always been skeptical about the Stream
> approach.  Maybe the iterator has potential to be slightly better, or
> could be made to do so.
> 

When we use it, we are primarily using StackWalker.walk() which is pretty hard not to use with lambdas and streams. 

As I said in the beginning - for logging the class, method and line number this problem could go away completely if the compiler could generate an object to pass us, as in “logger.error(__LOCATION__, “My Log Message”):”  C and C++ had this 20 years ago when I last worked in those languages and with the C preprocessor you could use macros to hide the extra parameter. I’ve thought about doing something similar in Java using byte code injection at compile time but it looks like it is just a huge amount of work to determine the method and line number and it gets complicated trying to find all the places to do it.

Ralph