Rewrite date & time formatting

[vy]

In accordance with this dev@ discussion, these changes

• Deprecate FixedDateTime and FastDateTime
• Adds the internal InstantFormatter contract
  • Adds InstantNumberFormatter for epoch-related number-emitting formatting operations
  • Adds the InstantPatternNumber contract for formatting based on a specified date & time patter
    • Adds InstantPatternThreadLocalCachedFormatter which wraps any InstantPatternNumber and caches its values in a ThreadLocal for reusage
    • Adds InstantPatternDynamicFormatter that uses Java's DateTimeFormatter under the hood such that the pattern is analyzed and parts that require a precision lower than or equal to minute are precomputed, cached, and updated per minute. That is, DateTimeFormatter is effectively only used for sub-minute parts, e.g., ss.SSS.

InstantPatternDynamicFormatter internals

For instance, given the pattern yyyy-MM-dd'T'HH:mm:ss.SSSX, the generated formatter will

1. Sequence the pattern and assign a time precision to each part (e.g., MM is of month precision)
2. Precompute and cache the output for parts that are of precision lower than or equal to minute (i.e., yyyy-MM-dd'T'HH:mm: and X) and cache it
3. Upon a formatting request, combine the cached outputs with the dynamic parts (i.e., ss.SSS)

GC implications

Since DateTimeFormatter is not garbage-free, neither the new InstantPatternDynamicFormatter is.

Performance implications

JDK: Azul Zulu 17.0.12
OS: GNU/Linux
Date & time pattern: yyyy-MM-dd'T'HH:mm:ss.SSS

InstantPatternFormatterBenchmark

This benchmark stresses instant formatting efficiency. 1000 instants are formatted per operation.

DateTimeFormatter        2.844 ± 0.310  ops/ms
InstantPatternFormatter  4.807 ± 1.039  ops/ms
FastDateFormat           6.847 ± 1.302  ops/ms
FixedDateFormat         39.497 ± 6.423  ops/ms

Interpretation: When used in isolation, FixedDF yields a throughput of ~8x compared to InstantPF.

InstantPatternFormatterImpactBenchmark

This benchmark stresses instant formatting efficiency when combined with PatternLayout configured with the [%t] %p %-40.40c{1.} %notEmpty{%x }- %m%n pattern. 1000 LogEvents are formatted per operation.

Using full log events (incl. exception, MDC & NDC):

DateTimeFormatter       0.039 ± 0.001  ops/ms
InstantPatternFormatter 0.039 ± 0.001  ops/ms
FastDateFormat          0.039 ± 0.001  ops/ms
FixedDateFormat         0.040 ± 0.001  ops/ms

Interpretation: When LogEvent contains an exception, instant formatting efficiency becomes irrelevant.

Using lite log events:

DateTimeFormatter       1.888 ± 0.106  ops/ms
InstantPatternFormatter 2.404 ± 0.184  ops/ms
FastDateFormat          2.567 ± 0.032  ops/ms
FixedDateFormat         4.793 ± 0.019  ops/ms

Interpretation: When LogEvent doesn't contain an exception, MDC/NDC field, etc., FixedDF yields a throughput of ~2x compared to InstantPF.

Bug implications

Fixes #2943.

[ppkarwasz]

We don't really need DTF to print sub-day patterns (hours, minutes, seconds, etc.).

@ppkarwasz, what do you mean? If the pattern is, say, yyyy-MM-dd HH:mm:ss.SSS, we cache yyyy-MM-dd HH:mm: part and update it once per minute. I think this once-per-minute cost is negligible in a real-world setup.

Are you sure DTF is garbage-free for these patterns? Can you add a test for it?

DTF is not garbage-free – no matter which method of DTF you use. Hence, neither our InstantPatternDynamicFormatter is garbage-free.

the PatternSequences can actually be pre-computed, which would improve the time to generate the formatters.

Agreed, but I doubt if this additional complexity brings any practical benefit. Even my JMH tests run for 30 seconds, that is, they don't even encounter any sequencing operation.

Allow me to remind that my aim with this PR is not to implement the fastest instant formatter on top of DTF, but implement the simplest one with acceptable performance. FixedDF and FastDF were enough of a lesson for what happens with unsolicited complexity.

[ppkarwasz]

Using an internal Log4j Core package in JSON Template Layout poses an encapsulation problem:

• JPMS needs an @ExportTo annotation.
• OSGi needs the package to be exported to anyone.

Since we clearly want to leave the minimal possible API cross-section to users and considering that o.a.l.l.core.time.InstantFormatter is already present, might I suggest to:

• move InstantFormatter to o.a.l.l.core.time.InstantFormatter (or o.a.l.l.core.time.spi.InstantFormatter to give more the impression it is not meant to be used by users).
• add a newInstance(String pattern, Locale locale, TimeZone timeZone) static method that currently will only return o.a.l.l.core.time.spi.internal implementations, but (if users request it) can be adapted in the future to use plugins/ServiceLoader.

[vy]

OSGi needs the package to be exported to anyone.

Isn't there any other way for OSGi? (Yes, I don't want to open up the new package & classes.)

[ppkarwasz]

IIRC, when the subject of exports ... to came out on dev@logging (or maybe the PMC meeting) the consensus was that we should either export a package to all users or don't export it at all.

As I stated above, we only need to put InstantFormatter in an exportable package. If the package has spi in it, users will know that it only should be used by Log4j Plugin implementors.