Yes, I was just thinking that. But if there was a bug fix along the way that added a single line of code that could now be causing the code not to be inlined.
Ralph > On Apr 2, 2021, at 12:38 AM, Remko Popma <[email protected]> wrote: > > On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <[email protected]> > wrote: > >> I will take a look at the link. What you are saying makes sense to a >> degree. However, the new is actually performed in Instant.create() which is >> 2 levels down in the call stack. Without having read the link I would >> wonder if that qualifies. >> > > That is at the code level, yes. But these get inlined when called > sufficiently often. > So it is difficult to reason about what is eligible for escape analysis > just from the code... > > > >> >> Ralph >> >>> On Apr 2, 2021, at 12:00 AM, Remko Popma <[email protected]> wrote: >>> >>> My understanding is that PreciseClock is garbage-free because the JVM >> does >>> escape analysis. >>> Here is the relevant code: >>> >>> public void init(MutableInstant mutableInstant) { >>> Instant instant = java.time.Clock.systemUTC().instant(); >>> mutableInstant.initFromEpochSecond(instant.getEpochSecond(), >>> instant.getNano()); >>> } >>> >>> The code calls the instant() method, which returns an Instant object. >>> We would think that this is not garbage-free, but it magically is thanks >> to >>> escape analysis! >>> >>> This Instant object is only used within the init(MutableInstant) method. >>> It is not allowed to "escape": the method accesses fields in Instant, and >>> passes these primitive values to the initFromEpochSecond method (and does >>> not pass the Instant object itself). >>> >>> In theory, JVM escape analysis is able to detect that the object is not >>> referenced outside that method, and stops allocating the object >> altogether, >>> and instead does something called "scalar replacement", where it just >> uses >>> the values that are actually being used, without putting them in an >> object >>> first and then getting them out of the object again to use these values. >>> More details here: https://www.beyondjava.net/escape-analysis-java and >>> https://shipilev.net/jvm/anatomy-quarks/18-scalar-replacement/ >>> >>> I think I tested this on Java 9, and the >>> Google java-allocation-instrumenter library could not detect allocations. >>> >>> Has that changed: do the garbage-free tests fail >>> for org.apache.logging.log4j.core.util.SystemClock? >>> >>> Note that when looking at this in a sampling profiler it may show >>> allocations. (We actually ran into this in a work project.) >>> Profiles tend to disable the optimizations that allow escape analysis, so >>> our method may show up as allocating when looked at in a profiler, while >> in >>> real life it will not (after sufficient warmup). >>> >>> >>> >>> On Fri, Apr 2, 2021 at 2:46 PM Ralph Goers <[email protected]> >>> wrote: >>> >>>> >>>> >>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <[email protected]> >>>> wrote: >>>>> >>>>> In thinking about this problem I suspect we never noticed that the >>>> PreciseClock version of our SystemClock class is not garbage free is >>>> because we previously ran all of our unit tests with Java 8. Now that >> they >>>> are using Java 11 that code is being exercised. >>>>> >>>>> I’ve looked at java.time.Clock and java.time.Instant. As far as I know >>>> those are the only two classes in Java that provide sub-millisecond >>>> granularity. Unfortunately there is no way to call them to extract the >>>> field data we need to initialize MutableInstant. I considered modifying >> our >>>> version of SystemClock to perform the same actions as java.time’s >>>> SystemClock but the relevant method there calls >>>> jdk.internal.misc.VM.getNanoTimeAdjustment() to correct the >> sub-millisecond >>>> portion. That is implemented as a native method and seems to only be >>>> available to be called by an application when something like --add-opens >>>> java.base/jdk.internal.misc=xxx is on the command line. >>>>> >>>>> I’ve also considered disabling the PreciseClock when garbage free mode >>>> is enabled but as far as I can tell we don’t have a single switch for >> that. >>>> So I would have to add yet another system property to control it. >>>> >>>> One other option is to modify the documentation to indicate timestamps >> are >>>> not garbage free. But this seems awful since virtually every log event >> has >>>> one. It would make more sense to use the property to determine which to >> use >>>> so user’s who wish to be garbage free can continue with millisecond >>>> granularity. >>>> >>>> Ralph >>>> >> >> >>
