You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@logging.apache.org by Ralph Goers <ra...@dslextreme.com> on 2021/04/02 05:38:43 UTC

Garbage Free Precise Time

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.

Ralph
 

Re: Garbage Free Precise Time

Posted by Ralph Goers <ra...@dslextreme.com>.
That isn’t the case when I ran it with Java 11 and the latest version of the allocation tool. Virtually everything failed since almost everything creates a timestamp.

I would suggest you checkout the master-java11 branch, uncomment the stuff in the SystemClock class and try it yourself.

Ralph

> On Apr 2, 2021, at 12:00 AM, Remko Popma <re...@gmail.com> 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 <ra...@dslextreme.com>
> wrote:
> 
>> 
>> 
>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <ra...@dslextreme.com>
>> 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
>> 



Re: Garbage Free Precise Time

Posted by Ralph Goers <ra...@dslextreme.com>.
I filed a bug report with OpenJDK but have not gotten a response yet. It isn’t viewable in their Jira system until it goes through triage.

I considered what you are proposing but decided against it because I don’t believe that will be allowed without runtime flags, so it cannot be enabled by default.

Ralph

> On Apr 20, 2021, at 5:03 AM, Remko Popma <re...@gmail.com> wrote:
> 
> I think I have a solution for this.
> 
> My solution involves copying most of the the logic in
> java.time.Clock.SystemClock.instance().
> This means accessing the VM class (in misc), so requires some changes to
> the modules config.
> 
> Is there a JIRA ticket for this issue?
> 
> On Thu, Apr 8, 2021 at 16:10 Ralph Goers <ra...@dslextreme.com> wrote:
> 
>> I spoke too soon.  It didn’t really pass on Java 16. The allocation
>> instrumenter was unable to instrument anything so it didn’t generate the
>> errors the test looks for. I tried with Java 12-14 and those all failed. In
>> Java 15 the JVM crashed.
>> 
>> Ralph
>> 
>>> On Apr 7, 2021, at 11:36 PM, Ralph Goers <ra...@dslextreme.com>
>> wrote:
>>> 
>>> I have modified the test to allow -DusePreciseClock=true to be passed
>> in. When I set it to true and run it in JDK 16 the test passes!  However, I
>> tried 3 versions of JDK 11 and it failed in all of them.
>>> 
>>> Ralph
>>> 
>>>> On Apr 2, 2021, at 2:54 PM, Ralph Goers <ra...@dslextreme.com>
>> wrote:
>>>> 
>>>> I just tried adding logic to call SystemClock.init() 100,000 times. It
>> made no difference. The GC test still fails.
>>>> 
>>>> Ralph
>>>> 
>>>>> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
>>>>> 
>>>>> Escape analysis can take quite a few iterations to take effect,
>> perhaps we need a few more tens of thousands of warmup cycles? Admittedly I
>> haven't taken a look at the failures yet and there's a great deal of
>> subtlety around this. I can try to take a closer look later, unfortunately
>> I've been overwhelmed lately.
>>>>> 
>>>>> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
>>>>>> Looking at the source repo I don’t see anything that changed after
>> support for the higher precision was added.
>>>>>> 
>>>>>> Ralph
>>>>>> 
>>>>>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <ralph.goers@dslextreme.com
>> <mailto:ralph.goers%40dslextreme.com>> wrote:
>>>>>>> 
>>>>>>> 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 <remko.popma@gmail.com
>> <mailto:remko.popma%40gmail.com>> wrote:
>>>>>>>> 
>>>>>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <
>> ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>>>>>>>> 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 <remko.popma@gmail.com
>> <mailto:remko.popma%40gmail.com>> 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 <
>> ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>>>>>>>>>> wrote:
>>>>>>>>>> 
>>>>>>>>>>> 
>>>>>>>>>>> 
>>>>>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <
>> ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>>>>>>>>>>> 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
>>>>>>>>>>> 
>>>>>>>>> 
>>>>>>>>> 
>>>>>>>>> 
>>>>>>> 
>>>>>>> 
>>>>>>> 
>>>>>> 
>>>>>> 
>>>>>> 
>>>>> 
>>>> 
>>>> 
>>>> 
>>> 
>>> 
>>> 
>> 
>> 
>> 



Re: Garbage Free Precise Time

Posted by Sixx XT <si...@gmail.com>.
Georgia is acting like they don't know about it but guess what they were in
my route to Chelsea was in my route to f****** PINES library in my route
that is Verizon Wireless in my route I have five different government
phones in my roofs may I got every phone carrier in my roof because they
stealing everything I know and it's still in the office took y'all did to
is not right we had to shut down because listen guess I'll just email and
email treyhaziq@gmail.com as email please

On Tue, Apr 20, 2021, 8:03 AM Remko Popma <re...@gmail.com> wrote:

> I think I have a solution for this.
>
> My solution involves copying most of the the logic in
> java.time.Clock.SystemClock.instance().
> This means accessing the VM class (in misc), so requires some changes to
> the modules config.
>
> Is there a JIRA ticket for this issue?
>
> On Thu, Apr 8, 2021 at 16:10 Ralph Goers <ra...@dslextreme.com>
> wrote:
>
> > I spoke too soon.  It didn’t really pass on Java 16. The allocation
> > instrumenter was unable to instrument anything so it didn’t generate the
> > errors the test looks for. I tried with Java 12-14 and those all failed.
> In
> > Java 15 the JVM crashed.
> >
> > Ralph
> >
> > > On Apr 7, 2021, at 11:36 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >
> > > I have modified the test to allow -DusePreciseClock=true to be passed
> > in. When I set it to true and run it in JDK 16 the test passes!
> However, I
> > tried 3 versions of JDK 11 and it failed in all of them.
> > >
> > > Ralph
> > >
> > >> On Apr 2, 2021, at 2:54 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >>
> > >> I just tried adding logic to call SystemClock.init() 100,000 times. It
> > made no difference. The GC test still fails.
> > >>
> > >> Ralph
> > >>
> > >>> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
> > >>>
> > >>> Escape analysis can take quite a few iterations to take effect,
> > perhaps we need a few more tens of thousands of warmup cycles?
> Admittedly I
> > haven't taken a look at the failures yet and there's a great deal of
> > subtlety around this. I can try to take a closer look later,
> unfortunately
> > I've been overwhelmed lately.
> > >>>
> > >>> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
> > >>>> Looking at the source repo I don’t see anything that changed after
> > support for the higher precision was added.
> > >>>>
> > >>>> Ralph
> > >>>>
> > >>>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <
> ralph.goers@dslextreme.com
> > <mailto:ralph.goers%40dslextreme.com>> wrote:
> > >>>>>
> > >>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> wrote:
> > >>>>>>
> > >>>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> 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 <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>> wrote:
> > >>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>>> 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
> > >>>>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>
> > >>>>>
> > >>>>>
> > >>>>
> > >>>>
> > >>>>
> > >>>
> > >>
> > >>
> > >>
> > >
> > >
> > >
> >
> >
> >
>

Re: Garbage Free Precise Time

Posted by Sixx XT <si...@gmail.com>.
Disgaea is my ruining my Chase man look I got to pay out and I'll be
willing to pay off I'll let you go in that remotely if you want to do it
it's just this son of a b**** out of my f****** rude just tell me what you
want to do you want me to download app I want you to get this son of a
b**** on my route and I'm going to watch you do this s*** cuz I don't know
how to do it that's the only reason he keeps popping up in the email he's
going to change the whole wheat pasta coat he changed the whole thing I
don't know how you got out you got help man's 145000 people I counted on a
screenshot

On Tue, Apr 20, 2021, 8:04 AM Sixx XT <si...@gmail.com> wrote:

> Man he's keeping me from getting a job
>
> On Tue, Apr 20, 2021, 8:03 AM Remko Popma <re...@gmail.com> wrote:
>
>> I think I have a solution for this.
>>
>> My solution involves copying most of the the logic in
>> java.time.Clock.SystemClock.instance().
>> This means accessing the VM class (in misc), so requires some changes to
>> the modules config.
>>
>> Is there a JIRA ticket for this issue?
>>
>> On Thu, Apr 8, 2021 at 16:10 Ralph Goers <ra...@dslextreme.com>
>> wrote:
>>
>> > I spoke too soon.  It didn’t really pass on Java 16. The allocation
>> > instrumenter was unable to instrument anything so it didn’t generate the
>> > errors the test looks for. I tried with Java 12-14 and those all
>> failed. In
>> > Java 15 the JVM crashed.
>> >
>> > Ralph
>> >
>> > > On Apr 7, 2021, at 11:36 PM, Ralph Goers <ra...@dslextreme.com>
>> > wrote:
>> > >
>> > > I have modified the test to allow -DusePreciseClock=true to be passed
>> > in. When I set it to true and run it in JDK 16 the test passes!
>> However, I
>> > tried 3 versions of JDK 11 and it failed in all of them.
>> > >
>> > > Ralph
>> > >
>> > >> On Apr 2, 2021, at 2:54 PM, Ralph Goers <ra...@dslextreme.com>
>> > wrote:
>> > >>
>> > >> I just tried adding logic to call SystemClock.init() 100,000 times.
>> It
>> > made no difference. The GC test still fails.
>> > >>
>> > >> Ralph
>> > >>
>> > >>> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
>> > >>>
>> > >>> Escape analysis can take quite a few iterations to take effect,
>> > perhaps we need a few more tens of thousands of warmup cycles?
>> Admittedly I
>> > haven't taken a look at the failures yet and there's a great deal of
>> > subtlety around this. I can try to take a closer look later,
>> unfortunately
>> > I've been overwhelmed lately.
>> > >>>
>> > >>> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
>> > >>>> Looking at the source repo I don’t see anything that changed after
>> > support for the higher precision was added.
>> > >>>>
>> > >>>> Ralph
>> > >>>>
>> > >>>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <
>> ralph.goers@dslextreme.com
>> > <mailto:ralph.goers%40dslextreme.com>> wrote:
>> > >>>>>
>> > >>>>> 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 <remko.popma@gmail.com
>> > <mailto:remko.popma%40gmail.com>> wrote:
>> > >>>>>>
>> > >>>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <
>> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>> > >>>>>> 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 <
>> remko.popma@gmail.com
>> > <mailto:remko.popma%40gmail.com>> 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 <
>> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>> > >>>>>>>> wrote:
>> > >>>>>>>>
>> > >>>>>>>>>
>> > >>>>>>>>>
>> > >>>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <
>> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>> > >>>>>>>>> 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
>> > >>>>>>>>>
>> > >>>>>>>
>> > >>>>>>>
>> > >>>>>>>
>> > >>>>>
>> > >>>>>
>> > >>>>>
>> > >>>>
>> > >>>>
>> > >>>>
>> > >>>
>> > >>
>> > >>
>> > >>
>> > >
>> > >
>> > >
>> >
>> >
>> >
>>
>

Re: Garbage Free Precise Time

Posted by Sixx XT <si...@gmail.com>.
Man he's keeping me from getting a job

On Tue, Apr 20, 2021, 8:03 AM Remko Popma <re...@gmail.com> wrote:

> I think I have a solution for this.
>
> My solution involves copying most of the the logic in
> java.time.Clock.SystemClock.instance().
> This means accessing the VM class (in misc), so requires some changes to
> the modules config.
>
> Is there a JIRA ticket for this issue?
>
> On Thu, Apr 8, 2021 at 16:10 Ralph Goers <ra...@dslextreme.com>
> wrote:
>
> > I spoke too soon.  It didn’t really pass on Java 16. The allocation
> > instrumenter was unable to instrument anything so it didn’t generate the
> > errors the test looks for. I tried with Java 12-14 and those all failed.
> In
> > Java 15 the JVM crashed.
> >
> > Ralph
> >
> > > On Apr 7, 2021, at 11:36 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >
> > > I have modified the test to allow -DusePreciseClock=true to be passed
> > in. When I set it to true and run it in JDK 16 the test passes!
> However, I
> > tried 3 versions of JDK 11 and it failed in all of them.
> > >
> > > Ralph
> > >
> > >> On Apr 2, 2021, at 2:54 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >>
> > >> I just tried adding logic to call SystemClock.init() 100,000 times. It
> > made no difference. The GC test still fails.
> > >>
> > >> Ralph
> > >>
> > >>> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
> > >>>
> > >>> Escape analysis can take quite a few iterations to take effect,
> > perhaps we need a few more tens of thousands of warmup cycles?
> Admittedly I
> > haven't taken a look at the failures yet and there's a great deal of
> > subtlety around this. I can try to take a closer look later,
> unfortunately
> > I've been overwhelmed lately.
> > >>>
> > >>> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
> > >>>> Looking at the source repo I don’t see anything that changed after
> > support for the higher precision was added.
> > >>>>
> > >>>> Ralph
> > >>>>
> > >>>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <
> ralph.goers@dslextreme.com
> > <mailto:ralph.goers%40dslextreme.com>> wrote:
> > >>>>>
> > >>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> wrote:
> > >>>>>>
> > >>>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> 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 <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>> wrote:
> > >>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>>> 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
> > >>>>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>
> > >>>>>
> > >>>>>
> > >>>>
> > >>>>
> > >>>>
> > >>>
> > >>
> > >>
> > >>
> > >
> > >
> > >
> >
> >
> >
>

Re: Garbage Free Precise Time

Posted by Sixx XT <si...@gmail.com>.
On like 21 now with Java 36 recovery and dups he can't kill the memory he's
even got me stuck back on this email I got to get rid of it its this whats
going on in 2016 that gave me SAR I didn't know I didn't know the whole
three I did not know I had it so jobs in Georgia won't hire me and I did
not understand why they kept treating me so bad but something on my ID from
a blood type down to going to the hospital I was being used by doctors and
they was abusing me so I got abused by Labor Department women I got a
really treated bad after they got that v g development Verizon there and
you'll see Verizon they took it from me when I mowed it to three and four G
when I build a dynamic for my computer that's how we got 5 G and so they
did what they gave it to somebody else but never gave me to pay under the
Apache codes Trulia the passage is a true founders of 5G  in 2013

On Tue, Apr 20, 2021, 8:03 AM Remko Popma <re...@gmail.com> wrote:

> I think I have a solution for this.
>
> My solution involves copying most of the the logic in
> java.time.Clock.SystemClock.instance().
> This means accessing the VM class (in misc), so requires some changes to
> the modules config.
>
> Is there a JIRA ticket for this issue?
>
> On Thu, Apr 8, 2021 at 16:10 Ralph Goers <ra...@dslextreme.com>
> wrote:
>
> > I spoke too soon.  It didn’t really pass on Java 16. The allocation
> > instrumenter was unable to instrument anything so it didn’t generate the
> > errors the test looks for. I tried with Java 12-14 and those all failed.
> In
> > Java 15 the JVM crashed.
> >
> > Ralph
> >
> > > On Apr 7, 2021, at 11:36 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >
> > > I have modified the test to allow -DusePreciseClock=true to be passed
> > in. When I set it to true and run it in JDK 16 the test passes!
> However, I
> > tried 3 versions of JDK 11 and it failed in all of them.
> > >
> > > Ralph
> > >
> > >> On Apr 2, 2021, at 2:54 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >>
> > >> I just tried adding logic to call SystemClock.init() 100,000 times. It
> > made no difference. The GC test still fails.
> > >>
> > >> Ralph
> > >>
> > >>> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
> > >>>
> > >>> Escape analysis can take quite a few iterations to take effect,
> > perhaps we need a few more tens of thousands of warmup cycles?
> Admittedly I
> > haven't taken a look at the failures yet and there's a great deal of
> > subtlety around this. I can try to take a closer look later,
> unfortunately
> > I've been overwhelmed lately.
> > >>>
> > >>> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
> > >>>> Looking at the source repo I don’t see anything that changed after
> > support for the higher precision was added.
> > >>>>
> > >>>> Ralph
> > >>>>
> > >>>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <
> ralph.goers@dslextreme.com
> > <mailto:ralph.goers%40dslextreme.com>> wrote:
> > >>>>>
> > >>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> wrote:
> > >>>>>>
> > >>>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> 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 <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>> wrote:
> > >>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>>> 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
> > >>>>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>
> > >>>>>
> > >>>>>
> > >>>>
> > >>>>
> > >>>>
> > >>>
> > >>
> > >>
> > >>
> > >
> > >
> > >
> >
> >
> >
>

Re: Garbage Free Precise Time

Posted by Matt Sicker <bo...@gmail.com>.
Will that work in Java 16+ where internals are no longer accessible
without additional compiler/runtime flags? This still seems like it
may require explicit support in the standard class library like how
other sun.misc classes got standardized eventually (like VarHandle).

On Tue, 20 Apr 2021 at 07:03, Remko Popma <re...@gmail.com> wrote:
>
> I think I have a solution for this.
>
> My solution involves copying most of the the logic in
> java.time.Clock.SystemClock.instance().
> This means accessing the VM class (in misc), so requires some changes to
> the modules config.
>
> Is there a JIRA ticket for this issue?
>
> On Thu, Apr 8, 2021 at 16:10 Ralph Goers <ra...@dslextreme.com> wrote:
>
> > I spoke too soon.  It didn’t really pass on Java 16. The allocation
> > instrumenter was unable to instrument anything so it didn’t generate the
> > errors the test looks for. I tried with Java 12-14 and those all failed. In
> > Java 15 the JVM crashed.
> >
> > Ralph
> >
> > > On Apr 7, 2021, at 11:36 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >
> > > I have modified the test to allow -DusePreciseClock=true to be passed
> > in. When I set it to true and run it in JDK 16 the test passes!  However, I
> > tried 3 versions of JDK 11 and it failed in all of them.
> > >
> > > Ralph
> > >
> > >> On Apr 2, 2021, at 2:54 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >>
> > >> I just tried adding logic to call SystemClock.init() 100,000 times. It
> > made no difference. The GC test still fails.
> > >>
> > >> Ralph
> > >>
> > >>> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
> > >>>
> > >>> Escape analysis can take quite a few iterations to take effect,
> > perhaps we need a few more tens of thousands of warmup cycles? Admittedly I
> > haven't taken a look at the failures yet and there's a great deal of
> > subtlety around this. I can try to take a closer look later, unfortunately
> > I've been overwhelmed lately.
> > >>>
> > >>> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
> > >>>> Looking at the source repo I don’t see anything that changed after
> > support for the higher precision was added.
> > >>>>
> > >>>> Ralph
> > >>>>
> > >>>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <ralph.goers@dslextreme.com
> > <mailto:ralph.goers%40dslextreme.com>> wrote:
> > >>>>>
> > >>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> wrote:
> > >>>>>>
> > >>>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> 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 <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>> wrote:
> > >>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>>> 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
> > >>>>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>
> > >>>>>
> > >>>>>
> > >>>>
> > >>>>
> > >>>>
> > >>>
> > >>
> > >>
> > >>
> > >
> > >
> > >
> >
> >
> >

Re: Garbage Free Precise Time

Posted by Sixx XT <si...@gmail.com>.
Ill look

On Tue, Apr 20, 2021, 8:03 AM Remko Popma <re...@gmail.com> wrote:

> I think I have a solution for this.
>
> My solution involves copying most of the the logic in
> java.time.Clock.SystemClock.instance().
> This means accessing the VM class (in misc), so requires some changes to
> the modules config.
>
> Is there a JIRA ticket for this issue?
>
> On Thu, Apr 8, 2021 at 16:10 Ralph Goers <ra...@dslextreme.com>
> wrote:
>
> > I spoke too soon.  It didn’t really pass on Java 16. The allocation
> > instrumenter was unable to instrument anything so it didn’t generate the
> > errors the test looks for. I tried with Java 12-14 and those all failed.
> In
> > Java 15 the JVM crashed.
> >
> > Ralph
> >
> > > On Apr 7, 2021, at 11:36 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >
> > > I have modified the test to allow -DusePreciseClock=true to be passed
> > in. When I set it to true and run it in JDK 16 the test passes!
> However, I
> > tried 3 versions of JDK 11 and it failed in all of them.
> > >
> > > Ralph
> > >
> > >> On Apr 2, 2021, at 2:54 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >>
> > >> I just tried adding logic to call SystemClock.init() 100,000 times. It
> > made no difference. The GC test still fails.
> > >>
> > >> Ralph
> > >>
> > >>> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
> > >>>
> > >>> Escape analysis can take quite a few iterations to take effect,
> > perhaps we need a few more tens of thousands of warmup cycles?
> Admittedly I
> > haven't taken a look at the failures yet and there's a great deal of
> > subtlety around this. I can try to take a closer look later,
> unfortunately
> > I've been overwhelmed lately.
> > >>>
> > >>> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
> > >>>> Looking at the source repo I don’t see anything that changed after
> > support for the higher precision was added.
> > >>>>
> > >>>> Ralph
> > >>>>
> > >>>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <
> ralph.goers@dslextreme.com
> > <mailto:ralph.goers%40dslextreme.com>> wrote:
> > >>>>>
> > >>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> wrote:
> > >>>>>>
> > >>>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> 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 <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>> wrote:
> > >>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>>> 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
> > >>>>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>
> > >>>>>
> > >>>>>
> > >>>>
> > >>>>
> > >>>>
> > >>>
> > >>
> > >>
> > >>
> > >
> > >
> > >
> >
> >
> >
>

Re: Garbage Free Precise Time

Posted by Sixx XT <si...@gmail.com>.
 those rewards system car dammit the reward system cards that they make
he's controlling my f****** voice to on my phone I can't stop it anyway
we're under our wrw so now we're back at R&R so now we're at Ruth Ruth so I
got to figure out how to get him on my roof long story short they took my
pill and started hacking people taking money out of your account and is
trying to frame me over and Georgia call me call me this morning wanted to
give me my bag treat me like s*** the last two cases they've been treating
me so dirty I've been harassed by police I made movies about it they won't
leave me alone and I'm an activist I don't like that s*** but they call me
at 7 so yeah I'm hated by a lot of people in the world and I've been shot
at and they call me a hack I'm not a hacker okay I just want to have a
normal life and get my kid back Microsoft manipulated me they gave me home
cheese to attend s computer it allowed them to come in and then the phone
from the computer that was sold to me on Facebook was a Enterprise computer
integrated to my f****** phone and then Mark Zuckerberg stupid ass won't
get sued for it and they just covering it up he sold me a car with a
goddamn run by emulator

On Tue, Apr 20, 2021, 8:03 AM Remko Popma <re...@gmail.com> wrote:

> I think I have a solution for this.
>
> My solution involves copying most of the the logic in
> java.time.Clock.SystemClock.instance().
> This means accessing the VM class (in misc), so requires some changes to
> the modules config.
>
> Is there a JIRA ticket for this issue?
>
> On Thu, Apr 8, 2021 at 16:10 Ralph Goers <ra...@dslextreme.com>
> wrote:
>
> > I spoke too soon.  It didn’t really pass on Java 16. The allocation
> > instrumenter was unable to instrument anything so it didn’t generate the
> > errors the test looks for. I tried with Java 12-14 and those all failed.
> In
> > Java 15 the JVM crashed.
> >
> > Ralph
> >
> > > On Apr 7, 2021, at 11:36 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >
> > > I have modified the test to allow -DusePreciseClock=true to be passed
> > in. When I set it to true and run it in JDK 16 the test passes!
> However, I
> > tried 3 versions of JDK 11 and it failed in all of them.
> > >
> > > Ralph
> > >
> > >> On Apr 2, 2021, at 2:54 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >>
> > >> I just tried adding logic to call SystemClock.init() 100,000 times. It
> > made no difference. The GC test still fails.
> > >>
> > >> Ralph
> > >>
> > >>> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
> > >>>
> > >>> Escape analysis can take quite a few iterations to take effect,
> > perhaps we need a few more tens of thousands of warmup cycles?
> Admittedly I
> > haven't taken a look at the failures yet and there's a great deal of
> > subtlety around this. I can try to take a closer look later,
> unfortunately
> > I've been overwhelmed lately.
> > >>>
> > >>> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
> > >>>> Looking at the source repo I don’t see anything that changed after
> > support for the higher precision was added.
> > >>>>
> > >>>> Ralph
> > >>>>
> > >>>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <
> ralph.goers@dslextreme.com
> > <mailto:ralph.goers%40dslextreme.com>> wrote:
> > >>>>>
> > >>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> wrote:
> > >>>>>>
> > >>>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> 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 <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>> wrote:
> > >>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>>> 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
> > >>>>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>
> > >>>>>
> > >>>>>
> > >>>>
> > >>>>
> > >>>>
> > >>>
> > >>
> > >>
> > >>
> > >
> > >
> > >
> >
> >
> >
>

Re: Garbage Free Precise Time

Posted by Sixx XT <si...@gmail.com>.
Walking the only way we can get it out the only way we can get him out you
got you want me to get permissions its ownership filed its it in The Roots
you tell me exactly what fauzi coaches okay but when you got to stop
emailing me on  he's back in there he's getting every email I get Mark
Zuckerberg got his boys out there at California going against us right now
with that fool

On Tue, Apr 20, 2021, 8:03 AM Remko Popma <re...@gmail.com> wrote:

> I think I have a solution for this.
>
> My solution involves copying most of the the logic in
> java.time.Clock.SystemClock.instance().
> This means accessing the VM class (in misc), so requires some changes to
> the modules config.
>
> Is there a JIRA ticket for this issue?
>
> On Thu, Apr 8, 2021 at 16:10 Ralph Goers <ra...@dslextreme.com>
> wrote:
>
> > I spoke too soon.  It didn’t really pass on Java 16. The allocation
> > instrumenter was unable to instrument anything so it didn’t generate the
> > errors the test looks for. I tried with Java 12-14 and those all failed.
> In
> > Java 15 the JVM crashed.
> >
> > Ralph
> >
> > > On Apr 7, 2021, at 11:36 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >
> > > I have modified the test to allow -DusePreciseClock=true to be passed
> > in. When I set it to true and run it in JDK 16 the test passes!
> However, I
> > tried 3 versions of JDK 11 and it failed in all of them.
> > >
> > > Ralph
> > >
> > >> On Apr 2, 2021, at 2:54 PM, Ralph Goers <ra...@dslextreme.com>
> > wrote:
> > >>
> > >> I just tried adding logic to call SystemClock.init() 100,000 times. It
> > made no difference. The GC test still fails.
> > >>
> > >> Ralph
> > >>
> > >>> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
> > >>>
> > >>> Escape analysis can take quite a few iterations to take effect,
> > perhaps we need a few more tens of thousands of warmup cycles?
> Admittedly I
> > haven't taken a look at the failures yet and there's a great deal of
> > subtlety around this. I can try to take a closer look later,
> unfortunately
> > I've been overwhelmed lately.
> > >>>
> > >>> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
> > >>>> Looking at the source repo I don’t see anything that changed after
> > support for the higher precision was added.
> > >>>>
> > >>>> Ralph
> > >>>>
> > >>>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <
> ralph.goers@dslextreme.com
> > <mailto:ralph.goers%40dslextreme.com>> wrote:
> > >>>>>
> > >>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> wrote:
> > >>>>>>
> > >>>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>> 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 <remko.popma@gmail.com
> > <mailto:remko.popma%40gmail.com>> 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 <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>> wrote:
> > >>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>
> > >>>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <
> > ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> > >>>>>>>>> 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
> > >>>>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>>>
> > >>>>>
> > >>>>>
> > >>>>>
> > >>>>
> > >>>>
> > >>>>
> > >>>
> > >>
> > >>
> > >>
> > >
> > >
> > >
> >
> >
> >
>

Re: Garbage Free Precise Time

Posted by Remko Popma <re...@gmail.com>.
I think I have a solution for this.

My solution involves copying most of the the logic in
java.time.Clock.SystemClock.instance().
This means accessing the VM class (in misc), so requires some changes to
the modules config.

Is there a JIRA ticket for this issue?

On Thu, Apr 8, 2021 at 16:10 Ralph Goers <ra...@dslextreme.com> wrote:

> I spoke too soon.  It didn’t really pass on Java 16. The allocation
> instrumenter was unable to instrument anything so it didn’t generate the
> errors the test looks for. I tried with Java 12-14 and those all failed. In
> Java 15 the JVM crashed.
>
> Ralph
>
> > On Apr 7, 2021, at 11:36 PM, Ralph Goers <ra...@dslextreme.com>
> wrote:
> >
> > I have modified the test to allow -DusePreciseClock=true to be passed
> in. When I set it to true and run it in JDK 16 the test passes!  However, I
> tried 3 versions of JDK 11 and it failed in all of them.
> >
> > Ralph
> >
> >> On Apr 2, 2021, at 2:54 PM, Ralph Goers <ra...@dslextreme.com>
> wrote:
> >>
> >> I just tried adding logic to call SystemClock.init() 100,000 times. It
> made no difference. The GC test still fails.
> >>
> >> Ralph
> >>
> >>> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
> >>>
> >>> Escape analysis can take quite a few iterations to take effect,
> perhaps we need a few more tens of thousands of warmup cycles? Admittedly I
> haven't taken a look at the failures yet and there's a great deal of
> subtlety around this. I can try to take a closer look later, unfortunately
> I've been overwhelmed lately.
> >>>
> >>> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
> >>>> Looking at the source repo I don’t see anything that changed after
> support for the higher precision was added.
> >>>>
> >>>> Ralph
> >>>>
> >>>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <ralph.goers@dslextreme.com
> <mailto:ralph.goers%40dslextreme.com>> wrote:
> >>>>>
> >>>>> 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 <remko.popma@gmail.com
> <mailto:remko.popma%40gmail.com>> wrote:
> >>>>>>
> >>>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <
> ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> >>>>>> 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 <remko.popma@gmail.com
> <mailto:remko.popma%40gmail.com>> 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 <
> ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> >>>>>>>> wrote:
> >>>>>>>>
> >>>>>>>>>
> >>>>>>>>>
> >>>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <
> ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> >>>>>>>>> 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
> >>>>>>>>>
> >>>>>>>
> >>>>>>>
> >>>>>>>
> >>>>>
> >>>>>
> >>>>>
> >>>>
> >>>>
> >>>>
> >>>
> >>
> >>
> >>
> >
> >
> >
>
>
>

Re: Garbage Free Precise Time

Posted by Ralph Goers <ra...@dslextreme.com>.
I spoke too soon.  It didn’t really pass on Java 16. The allocation instrumenter was unable to instrument anything so it didn’t generate the errors the test looks for. I tried with Java 12-14 and those all failed. In Java 15 the JVM crashed.

Ralph

> On Apr 7, 2021, at 11:36 PM, Ralph Goers <ra...@dslextreme.com> wrote:
> 
> I have modified the test to allow -DusePreciseClock=true to be passed in. When I set it to true and run it in JDK 16 the test passes!  However, I tried 3 versions of JDK 11 and it failed in all of them.
> 
> Ralph
> 
>> On Apr 2, 2021, at 2:54 PM, Ralph Goers <ra...@dslextreme.com> wrote:
>> 
>> I just tried adding logic to call SystemClock.init() 100,000 times. It made no difference. The GC test still fails.
>> 
>> Ralph
>> 
>>> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
>>> 
>>> Escape analysis can take quite a few iterations to take effect, perhaps we need a few more tens of thousands of warmup cycles? Admittedly I haven't taken a look at the failures yet and there's a great deal of subtlety around this. I can try to take a closer look later, unfortunately I've been overwhelmed lately.
>>> 
>>> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
>>>> Looking at the source repo I don’t see anything that changed after support for the higher precision was added.
>>>> 
>>>> Ralph
>>>> 
>>>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>> wrote:
>>>>> 
>>>>> 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 <remko.popma@gmail.com <mailto:remko.popma%40gmail.com>> wrote:
>>>>>> 
>>>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>>>>>> 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 <remko.popma@gmail.com <mailto:remko.popma%40gmail.com>> 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 <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>>>>>>>> wrote:
>>>>>>>> 
>>>>>>>>> 
>>>>>>>>> 
>>>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>>>>>>>>> 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
>>>>>>>>> 
>>>>>>> 
>>>>>>> 
>>>>>>> 
>>>>> 
>>>>> 
>>>>> 
>>>> 
>>>> 
>>>> 
>>> 
>> 
>> 
>> 
> 
> 
> 



Re: Garbage Free Precise Time

Posted by Ralph Goers <ra...@dslextreme.com>.
I have modified the test to allow -DusePreciseClock=true to be passed in. When I set it to true and run it in JDK 16 the test passes!  However, I tried 3 versions of JDK 11 and it failed in all of them.

Ralph

> On Apr 2, 2021, at 2:54 PM, Ralph Goers <ra...@dslextreme.com> wrote:
> 
> I just tried adding logic to call SystemClock.init() 100,000 times. It made no difference. The GC test still fails.
> 
> Ralph
> 
>> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
>> 
>> Escape analysis can take quite a few iterations to take effect, perhaps we need a few more tens of thousands of warmup cycles? Admittedly I haven't taken a look at the failures yet and there's a great deal of subtlety around this. I can try to take a closer look later, unfortunately I've been overwhelmed lately.
>> 
>> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
>>> Looking at the source repo I don’t see anything that changed after support for the higher precision was added.
>>> 
>>> Ralph
>>> 
>>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>> wrote:
>>>> 
>>>> 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 <remko.popma@gmail.com <mailto:remko.popma%40gmail.com>> wrote:
>>>>> 
>>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>>>>> 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 <remko.popma@gmail.com <mailto:remko.popma%40gmail.com>> 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 <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>>>>>>> wrote:
>>>>>>> 
>>>>>>>> 
>>>>>>>> 
>>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>>>>>>>> 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
>>>>>>>> 
>>>>>> 
>>>>>> 
>>>>>> 
>>>> 
>>>> 
>>>> 
>>> 
>>> 
>>> 
>> 
> 
> 
> 



Re: Garbage Free Precise Time

Posted by Ralph Goers <ra...@dslextreme.com>.
I just tried adding logic to call SystemClock.init() 100,000 times. It made no difference. The GC test still fails.

Ralph

> On Apr 2, 2021, at 7:18 AM, Carter Kozak <ck...@ckozak.net> wrote:
> 
> Escape analysis can take quite a few iterations to take effect, perhaps we need a few more tens of thousands of warmup cycles? Admittedly I haven't taken a look at the failures yet and there's a great deal of subtlety around this. I can try to take a closer look later, unfortunately I've been overwhelmed lately.
> 
> On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
>> Looking at the source repo I don’t see anything that changed after support for the higher precision was added.
>> 
>> Ralph
>> 
>>> On Apr 2, 2021, at 12:44 AM, Ralph Goers <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>> wrote:
>>> 
>>> 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 <remko.popma@gmail.com <mailto:remko.popma%40gmail.com>> wrote:
>>>> 
>>>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>>>> 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 <remko.popma@gmail.com <mailto:remko.popma%40gmail.com>> 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 <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>>>>>> wrote:
>>>>>> 
>>>>>>> 
>>>>>>> 
>>>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
>>>>>>> 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
>>>>>>> 
>>>>> 
>>>>> 
>>>>> 
>>> 
>>> 
>>> 
>> 
>> 
>> 
> 



Re: Garbage Free Precise Time

Posted by Carter Kozak <ck...@ckozak.net>.
Escape analysis can take quite a few iterations to take effect, perhaps we need a few more tens of thousands of warmup cycles? Admittedly I haven't taken a look at the failures yet and there's a great deal of subtlety around this. I can try to take a closer look later, unfortunately I've been overwhelmed lately.

On Fri, Apr 2, 2021, at 03:59, Ralph Goers wrote:
> Looking at the source repo I don’t see anything that changed after support for the higher precision was added.
> 
> Ralph
> 
> > On Apr 2, 2021, at 12:44 AM, Ralph Goers <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>> wrote:
> > 
> > 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 <remko.popma@gmail.com <mailto:remko.popma%40gmail.com>> wrote:
> >> 
> >> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> >> 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 <remko.popma@gmail.com <mailto:remko.popma%40gmail.com>> 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 <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> >>>> wrote:
> >>>> 
> >>>>> 
> >>>>> 
> >>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <ralph.goers@dslextreme.com <mailto:ralph.goers%40dslextreme.com>>
> >>>>> 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
> >>>>> 
> >>> 
> >>> 
> >>> 
> > 
> > 
> > 
> 
> 
> 

Re: Garbage Free Precise Time

Posted by Ralph Goers <ra...@dslextreme.com>.
Looking at the source repo I don’t see anything that changed after support for the higher precision was added.

Ralph

> On Apr 2, 2021, at 12:44 AM, Ralph Goers <ra...@dslextreme.com> wrote:
> 
> 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 <re...@gmail.com> wrote:
>> 
>> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <ra...@dslextreme.com>
>> 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 <re...@gmail.com> 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 <ra...@dslextreme.com>
>>>> wrote:
>>>> 
>>>>> 
>>>>> 
>>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <ra...@dslextreme.com>
>>>>> 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
>>>>> 
>>> 
>>> 
>>> 
> 
> 
> 



Re: Garbage Free Precise Time

Posted by Ralph Goers <ra...@dslextreme.com>.
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 <re...@gmail.com> wrote:
> 
> On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <ra...@dslextreme.com>
> 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 <re...@gmail.com> 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 <ra...@dslextreme.com>
>>> wrote:
>>> 
>>>> 
>>>> 
>>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <ra...@dslextreme.com>
>>>> 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
>>>> 
>> 
>> 
>> 



Re: Garbage Free Precise Time

Posted by Remko Popma <re...@gmail.com>.
On Fri, Apr 2, 2021 at 4:26 PM Ralph Goers <ra...@dslextreme.com>
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 <re...@gmail.com> 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 <ra...@dslextreme.com>
> > wrote:
> >
> >>
> >>
> >>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <ra...@dslextreme.com>
> >> 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
> >>
>
>
>

Re: Garbage Free Precise Time

Posted by Ralph Goers <ra...@dslextreme.com>.
I should also add that I tested with Amazon Correto

openjdk version "11.0.10" 2021-01-19 LTS
OpenJDK Runtime Environment Corretto-11.0.10.9.1 (build 11.0.10+9-LTS)
OpenJDK 64-Bit Server VM Corretto-11.0.10.9.1 (build 11.0.10+9-LTS, mixed mode)

This is what my employer has decided to use since AdoptOpenJDK doesn’t have access to the Java test kit so can’t be Java certified.  Although I have Oracle’s Java 11 installed I rarely use it due to the licensing issues.

Ralph

> On Apr 2, 2021, at 12:25 AM, Ralph Goers <ra...@dslextreme.com> 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.
> 
> Ralph
> 
>> On Apr 2, 2021, at 12:00 AM, Remko Popma <re...@gmail.com> 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 <ra...@dslextreme.com>
>> wrote:
>> 
>>> 
>>> 
>>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <ra...@dslextreme.com>
>>> 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
>>> 
> 
> 
> 



Re: Garbage Free Precise Time

Posted by Ralph Goers <ra...@dslextreme.com>.
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.

Ralph

> On Apr 2, 2021, at 12:00 AM, Remko Popma <re...@gmail.com> 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 <ra...@dslextreme.com>
> wrote:
> 
>> 
>> 
>>> On Apr 1, 2021, at 10:38 PM, Ralph Goers <ra...@dslextreme.com>
>> 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
>> 



Re: Garbage Free Precise Time

Posted by Remko Popma <re...@gmail.com>.
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 <ra...@dslextreme.com>
wrote:

>
>
> > On Apr 1, 2021, at 10:38 PM, Ralph Goers <ra...@dslextreme.com>
> 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
>

Re: Garbage Free Precise Time

Posted by Ralph Goers <ra...@dslextreme.com>.

> On Apr 1, 2021, at 10:38 PM, Ralph Goers <ra...@dslextreme.com> 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