Interesting. I ran the test with openjdk version "16" 2021-03-16 OpenJDK Runtime Environment (build 16+36-2231) OpenJDK 64-Bit Server VM (build 16+36-2231, mixed mode, sharing)
and it passed. I then ran it with openjdk version "11.0.2" 2019-01-15 OpenJDK Runtime Environment 18.9 (build 11.0.2+9) OpenJDK 64-Bit Server VM 18.9 (build 11.0.2+9, mixed mode) and java version "11.0.9" 2020-10-20 LTS Java(TM) SE Runtime Environment 18.9 (build 11.0.9+7-LTS) Java HotSpot(TM) 64-Bit Server VM 18.9 (build 11.0.9+7-LTS, mixed mode) and java version "11.0.10" 2021-01-19 LTS Java(TM) SE Runtime Environment 18.9 (build 11.0.10+8-LTS-162) Java HotSpot(TM) 64-Bit Server VM 18.9 (build 11.0.10+8-LTS-162, mixed mode) and it failed with all of them. Ralph > On Apr 6, 2021, at 3:22 PM, Ralph Goers <ralph.go...@dslextreme.com> wrote: > > I am using > > 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) > > Our test uses > <dependency> > <groupId>com.google.code.java-allocation-instrumenter</groupId> > <artifactId>java-allocation-instrumenter</artifactId> > <version>3.3.0</version> > </dependency> > to validate that it is not allocating any objects. > > If you want to test it yourself you can do > > git clone https://github.com/apache/logging-log4j2.git > <https://github.com/apache/logging-log4j2.git> > cd logging-log4j2 > mvn -DskipTests=true clean install > cd log4j-core > mvn surefire:test -Dtest=GcFreeSynchronousLoggingTest > -Dmaven.surefire.debug="-Dlog4j2.usePreciseClock=true” > > When it fails you will see a strange message with > > I just allocated the object 2021-04-06T21:55:20.878377Z of type > java/time/Instant whose size is 24 ==> expected: <true> but was: <false> > > Ralph > >> On Apr 6, 2021, at 9:53 AM, Peter Levart <peter.lev...@gmail.com> wrote: >> >> Hi Ralph, >> >> >> Which version of JDK did you try running the code. I tried the following >> benchmark: >> >> >> @BenchmarkMode(Mode.AverageTime) >> @Fork(value = 1) >> @Warmup(iterations = 5, time = 1) >> @Measurement(iterations = 10, time = 1) >> @OutputTimeUnit(TimeUnit.NANOSECONDS) >> @State(Scope.Benchmark) >> public class InstantBench { >> >> @Benchmark >> public long epochMilli() { >> Instant instant = Clock.systemUTC().instant(); >> return instant.toEpochMilli(); >> } >> } >> >> >> And didn't get any heap allocation on either JDK 11: >> >> >> Benchmark Mode Cnt Score Error Units >> InstantBench.epochMilli avgt 10 34.722 ± 0.328 >> ns/op >> InstantBench.epochMilli:·gc.alloc.rate avgt 10 ≈ 10⁻⁴ >> MB/sec >> InstantBench.epochMilli:·gc.alloc.rate.norm avgt 10 ≈ 10⁻⁵ >> B/op >> InstantBench.epochMilli:·gc.count avgt 10 ≈ 0 >> counts >> >> >> ..nor on JDK 16: >> >> >> Benchmark Mode Cnt Score Error Units >> InstantBench.epochMilli avgt 10 33.612 ± 0.258 >> ns/op >> InstantBench.epochMilli:·gc.alloc.rate avgt 10 ≈ 10⁻⁴ >> MB/sec >> InstantBench.epochMilli:·gc.alloc.rate.norm avgt 10 ≈ 10⁻⁵ >> B/op >> InstantBench.epochMilli:·gc.count avgt 10 ≈ 0 >> counts >> >> >> Regards, Peter >> >> On 4/6/21 8:17 AM, Ralph Goers wrote: >>> Yes, I am aware that the Instant is constructed from the two values. That >>> is exactly why I was hoping I could pass in an object where the values of >>> those two fields could be injected. This would still allow Instant to be >>> immutable but allow Log4j to update one of the pre-existing Clock instances >>> it is managing. That would require that a new Interface be defined with the >>> two set methods and a new static method in the Clock class. >>> >>> Getting the value in microseconds would probably be a middle ground that >>> could also work considering that is the best resolution available on most >>> hardware today. >>> >>> Whichever is implemented I suspect getting it back ported to Java 11 is >>> unlikely? According to the surveys I’ve seen the majority of users are >>> still on Java 8. Given that, I’d be surprised if there is a mad rush to >>> adopt Java 17 very soon. Given where things are I’m not even sure how >>> likely it is this could make it in for Java 17. The irony here is that the >>> folks who need to run garbage free are also the ones most likely to need a >>> Clock with higher resolution. Right now they can’t have both. >>> >>> Ralph >>> >>>> On Apr 5, 2021, at 1:26 PM, Roger Riggs <roger.ri...@oracle.com> wrote: >>>> >>>> Hi, >>>> >>>> Java does not have a data type with enough resolution to hold a full >>>> nanosecond value. >>>> Hence the implementation of Instant holding seconds and nanos. >>>> >>>> There is an long dormant enhancement request to return micro-seconds as a >>>> long. >>>> 8196003 <https://bugs.openjdk.java.net/browse/JDK-8196003> java.time >>>> Instant and Duration methods for microseconds >>>> >>>> That might be useful if the application gets enough resolution from >>>> microseconds. >>>> There might be some clever interpolation between System.currentTimeMillis() >>>> and adjusting with System.nanoTime(). >>>> Though it would likely not be exactly synchronized with the values from >>>> Instant. >>>> >>>> Regards, Roger >>>> >>>> >>>> On 4/5/21 3:56 PM, Brian Goetz wrote: >>>>> Project Valhalla will allow Instant to be migrated to a primitive class, >>>>> which would address your problem. >>>>> >>>>> On 4/2/2021 7:47 PM, Ralph Goers wrote: >>>>>> Log4j 2 supports the notion of a PreciseClock - one that can be >>>>>> initialized to something more precise than a millisecond. At the same >>>>>> time it also supports running with no heap allocations in certain >>>>>> circumstances. I am in the process of moving our master branch to >>>>>> require Java 11 as the minimum. In doing so I am encountering unit test >>>>>> errors while verifying that logging is garbage free. They all occur >>>>>> allocating an Instant. >>>>>> >>>>>> The code we have simply does >>>>>> >>>>>> public void init(MutableInstant mutableInstant) { >>>>>> Instant instant = java.time.Clock.systemUTC().instant(); >>>>>> mutableInstant.initFromEpochSecond(instant.getEpochSecond(), >>>>>> instant.getNano()); >>>>>> } >>>>>> In our previous tests we had thought the allocation was being eliminated >>>>>> due to escape analysis since the data is being extracted from the >>>>>> Instant and not passed along. However, after upgrading the Google test >>>>>> library and the JDK version it appears that is not the case. >>>>>> Ideally we would really like something like >>>>>> >>>>>> public void init(MutableInstant mutableInstant) { >>>>>> java.time.Clock.systemUTC().initInstant(mutableInstant); >>>>>> } >>>>>> >>>>>> where Mutable instant would implement an interface that has the two set >>>>>> methods.The method would execute the same logic that is in the instant() >>>>>> method but instead of creating a new Instant it would call the set >>>>>> methods for the provided object. >>>>>> >>>>>> This would allow us to either have the MutableInstants in ThreadLocals >>>>>> or some other mechanism to ensure they are thread safe and have no heap >>>>>> allocations. As it stands now I see no way to gain access to the higher >>>>>> precision clock without memory allocation. >>>>>> >>>>>> Do you know of another way to do this? Am I missing something? >>>>>> >>>>>> Ralph >>>> >>> >> > >
