From cba3b5fb1adc92231f08c4cd68351e7a3aa41479 Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Fri, 27 Dec 2024 20:02:27 +0100 Subject: [PATCH 01/15] Use garbage-free formatter for `s` and `S` patterns This PR improves #3139, by introducing a new `InstantPatternFormatter` for patterns of the form "ss\.S{n}". Unlike the previous formatter based on `DateTimeFormatter`, the formatter is garbage-free. We also simplify the merging algorithm for pattern formatter factories, by moving the merging logic to the pattern formatter factories themselves. This PR does not contain a separate change log entry, since #3139 has not been published yet. Fixes #3337. --- .../InstantPatternDynamicFormatterTest.java | 100 +-- .../InstantPatternDynamicFormatter.java | 604 ++++++++---------- 2 files changed, 314 insertions(+), 390 deletions(-) diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java index 210689fe356..2eea54bc000 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java @@ -17,7 +17,6 @@ package org.apache.logging.log4j.core.util.internal.instant; import static java.util.Arrays.asList; -import static java.util.Collections.singletonList; import static org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.sequencePattern; import static org.assertj.core.api.Assertions.assertThat; @@ -32,10 +31,9 @@ import java.util.stream.IntStream; import java.util.stream.Stream; import org.apache.logging.log4j.core.time.MutableInstant; -import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.CompositePatternSequence; -import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.DynamicPatternSequence; -import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.PatternSequence; -import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.StaticPatternSequence; +import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.DateTimeFormatterPatternFormatterFactory; +import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.PatternFormatterFactory; +import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.SecondPatternFormatterFactory; import org.apache.logging.log4j.util.Constants; import org.junit.jupiter.params.ParameterizedTest; import org.junit.jupiter.params.provider.Arguments; @@ -47,8 +45,10 @@ class InstantPatternDynamicFormatterTest { @ParameterizedTest @MethodSource("sequencingTestCases") void sequencing_should_work( - final String pattern, final ChronoUnit thresholdPrecision, final List expectedSequences) { - final List actualSequences = sequencePattern(pattern, thresholdPrecision); + final String pattern, + final ChronoUnit thresholdPrecision, + final List expectedSequences) { + final List actualSequences = sequencePattern(pattern, thresholdPrecision); assertThat(actualSequences).isEqualTo(expectedSequences); } @@ -56,25 +56,19 @@ static List sequencingTestCases() { final List testCases = new ArrayList<>(); // `SSSX` should be treated constant for daily updates - testCases.add(Arguments.of("SSSX", ChronoUnit.DAYS, singletonList(pCom(pDyn("SSS"), pDyn("X"))))); + testCases.add(Arguments.of("SSSX", ChronoUnit.DAYS, asList(pMilliSec(), pDyn("X")))); // `yyyyMMddHHmmssSSSX` instant cache updated hourly testCases.add(Arguments.of( "yyyyMMddHHmmssSSSX", ChronoUnit.HOURS, - asList( - pCom(pDyn("yyyy"), pDyn("MM"), pDyn("dd"), pDyn("HH")), - pCom(pDyn("mm"), pDyn("ss"), pDyn("SSS")), - pDyn("X")))); + asList(pDyn("yyyyMMddHH", ChronoUnit.HOURS), pDyn("mm"), pSec("", 3), pDyn("X")))); // `yyyyMMddHHmmssSSSX` instant cache updated per minute testCases.add(Arguments.of( "yyyyMMddHHmmssSSSX", ChronoUnit.MINUTES, - asList( - pCom(pDyn("yyyy"), pDyn("MM"), pDyn("dd"), pDyn("HH"), pDyn("mm")), - pCom(pDyn("ss"), pDyn("SSS")), - pDyn("X")))); + asList(pDyn("yyyyMMddHHmm", ChronoUnit.MINUTES), pSec("", 3), pDyn("X")))); // ISO9601 instant cache updated daily final String iso8601InstantPattern = "yyyy-MM-dd'T'HH:mm:ss.SSSX"; @@ -82,77 +76,50 @@ static List sequencingTestCases() { iso8601InstantPattern, ChronoUnit.DAYS, asList( - pCom(pDyn("yyyy"), pSta("-"), pDyn("MM"), pSta("-"), pDyn("dd"), pSta("T")), - pCom( - pDyn("HH"), - pSta(":"), - pDyn("mm"), - pSta(":"), - pDyn("ss"), - pSta("."), - pDyn("SSS"), - pDyn("X"))))); + pDyn("yyyy'-'MM'-'dd'T'", ChronoUnit.DAYS), + pDyn("HH':'mm':'", ChronoUnit.MINUTES), + pSec(".", 3), + pDyn("X")))); // ISO9601 instant cache updated per minute testCases.add(Arguments.of( iso8601InstantPattern, ChronoUnit.MINUTES, - asList( - pCom( - pDyn("yyyy"), - pSta("-"), - pDyn("MM"), - pSta("-"), - pDyn("dd"), - pSta("T"), - pDyn("HH"), - pSta(":"), - pDyn("mm"), - pSta(":")), - pCom(pDyn("ss"), pSta("."), pDyn("SSS")), - pDyn("X")))); + asList(pDyn("yyyy'-'MM'-'dd'T'HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 3), pDyn("X")))); // ISO9601 instant cache updated per second testCases.add(Arguments.of( iso8601InstantPattern, ChronoUnit.SECONDS, - asList( - pCom( - pDyn("yyyy"), - pSta("-"), - pDyn("MM"), - pSta("-"), - pDyn("dd"), - pSta("T"), - pDyn("HH"), - pSta(":"), - pDyn("mm"), - pSta(":"), - pDyn("ss"), - pSta(".")), - pDyn("SSS"), - pDyn("X")))); + asList(pDyn("yyyy'-'MM'-'dd'T'HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 3), pDyn("X")))); + + // Seconds and micros + testCases.add(Arguments.of( + "HH:mm:ss.SSSSSS", ChronoUnit.MINUTES, asList(pDyn("HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 6)))); return testCases; } - private static CompositePatternSequence pCom(final PatternSequence... sequences) { - return new CompositePatternSequence(asList(sequences)); + private static DateTimeFormatterPatternFormatterFactory pDyn(final String pattern) { + return new DateTimeFormatterPatternFormatterFactory(pattern); + } + + private static DateTimeFormatterPatternFormatterFactory pDyn(final String pattern, final ChronoUnit precision) { + return new DateTimeFormatterPatternFormatterFactory(pattern, precision); } - private static DynamicPatternSequence pDyn(final String pattern) { - return new DynamicPatternSequence(pattern); + private static SecondPatternFormatterFactory pSec(String separator, int fractionalDigits) { + return new SecondPatternFormatterFactory(true, separator, fractionalDigits); } - private static StaticPatternSequence pSta(final String literal) { - return new StaticPatternSequence(literal); + private static SecondPatternFormatterFactory pMilliSec() { + return new SecondPatternFormatterFactory(false, "", 3); } @ParameterizedTest @ValueSource( strings = { // Basics - "S", "SSSSSSS", "SSSSSSSSS", "n", @@ -163,8 +130,7 @@ private static StaticPatternSequence pSta(final String literal) { "yyyy-MM-dd HH:mm:ss,SSSSSSS", "yyyy-MM-dd HH:mm:ss,SSSSSSSS", "yyyy-MM-dd HH:mm:ss,SSSSSSSSS", - "yyyy-MM-dd'T'HH:mm:ss.SSSSSSSSS", - "yyyy-MM-dd'T'HH:mm:ss.SXXX" + "yyyy-MM-dd'T'HH:mm:ss.SSSSSSSSS" }) void should_recognize_patterns_of_nano_precision(final String pattern) { assertPatternPrecision(pattern, ChronoUnit.NANOS); @@ -351,7 +317,9 @@ static Stream formatterInputs(final String pattern) { private static MutableInstant randomInstant() { final MutableInstant instant = new MutableInstant(); - final long epochSecond = RANDOM.nextInt(1_621_280_470); // 2021-05-17 21:41:10 + // In the 1970's some time zones had sub-minute offsets to UTC, e.g., Africa/Monrovia + final int startEighties = 315_532_800; + final long epochSecond = startEighties + RANDOM.nextInt(1_621_280_470 - startEighties); // 2021-05-17 21:41:10 final int epochSecondNano = randomNanos(); instant.initFromEpochSecond(epochSecond, epochSecondNano); return instant; diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java index 9c93dd34066..96b0def5f12 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java @@ -29,10 +29,11 @@ import java.util.Objects; import java.util.TimeZone; import java.util.concurrent.atomic.AtomicReference; -import java.util.function.Supplier; +import java.util.function.BiFunction; import java.util.stream.Collectors; import org.apache.logging.log4j.core.time.Instant; import org.apache.logging.log4j.core.time.MutableInstant; +import org.apache.logging.log4j.util.Strings; import org.jspecify.annotations.Nullable; /** @@ -164,7 +165,7 @@ private static InstantPatternFormatter createFormatter( final Instant creationInstant) { // Sequence the pattern and create associated formatters - final List sequences = sequencePattern(pattern, precisionThreshold); + final List sequences = sequencePattern(pattern, precisionThreshold); final List formatters = sequences.stream() .map(sequence -> { final InstantPatternFormatter formatter = sequence.createFormatter(locale, timeZone); @@ -204,7 +205,10 @@ public void formatTo(final StringBuilder buffer, final Instant instant) { // Combine all extracted formatters into one default: - final ChronoUnit precision = new CompositePatternSequence(sequences).precision; + final ChronoUnit precision = formatters.stream() + .map(InstantFormatter::getPrecision) + .min(Comparator.comparing(ChronoUnit::getDuration)) + .get(); return new AbstractFormatter(pattern, locale, timeZone, precision) { @Override public void formatTo(final StringBuilder buffer, final Instant instant) { @@ -218,17 +222,27 @@ public void formatTo(final StringBuilder buffer, final Instant instant) { } } - static List sequencePattern(final String pattern, final ChronoUnit precisionThreshold) { - List sequences = sequencePattern(pattern); - final List mergedSequences = mergeDynamicSequences(sequences, precisionThreshold); - return mergeConsequentEffectivelyConstantSequences(mergedSequences, precisionThreshold); + static List sequencePattern(final String pattern, final ChronoUnit precisionThreshold) { + List sequences = sequencePattern(pattern, (l, p) -> { + switch (l) { + case 's': + return new SecondPatternFormatterFactory(true, "", 0); + case 'S': + return new SecondPatternFormatterFactory(false, "", p.length()); + default: + return new DateTimeFormatterPatternFormatterFactory(p); + } + }); + return mergeFactories(sequences, precisionThreshold); } - private static List sequencePattern(final String pattern) { + static List sequencePattern( + final String pattern, + BiFunction dynamicFormatterFactoryProvider) { if (pattern.isEmpty()) { return Collections.emptyList(); } - final List sequences = new ArrayList<>(); + final List sequences = new ArrayList<>(); for (int startIndex = 0; startIndex < pattern.length(); ) { final char c = pattern.charAt(startIndex); @@ -240,7 +254,7 @@ private static List sequencePattern(final String pattern) { endIndex++; } final String sequenceContent = pattern.substring(startIndex, endIndex); - final PatternSequence sequence = new DynamicPatternSequence(sequenceContent); + final PatternFormatterFactory sequence = dynamicFormatterFactoryProvider.apply(c, sequenceContent); sequences.add(sequence); startIndex = endIndex; } @@ -256,19 +270,19 @@ else if (c == '\'') { } final String sequenceLiteral = (startIndex + 1) == endIndex ? "'" : pattern.substring(startIndex + 1, endIndex); - final PatternSequence sequence = new StaticPatternSequence(sequenceLiteral); + final PatternFormatterFactory sequence = new StaticPatternFormatterFactory(sequenceLiteral); sequences.add(sequence); startIndex = endIndex + 1; } // Handle unknown literal else { - final PatternSequence sequence = new StaticPatternSequence("" + c); + final PatternFormatterFactory sequence = new StaticPatternFormatterFactory("" + c); sequences.add(sequence); startIndex++; } } - return mergeConsequentStaticPatternSequences(sequences); + return sequences; } private static boolean isDynamicPatternLetter(final char c) { @@ -276,111 +290,16 @@ private static boolean isDynamicPatternLetter(final char c) { } /** - * Merges consequent static sequences. + * Merges sequences of formatter factories using {@link PatternFormatterFactory#tryMerge}. * *

- * For example, the sequencing of the {@code [MM-dd] HH:mm} pattern will create two static sequences for {@code ]} (right brace) and {@code } (whitespace) characters. - * This method will combine such consequent static sequences into one. + * For example, given the {@code yyyy-MM-dd'T'HH:mm:ss.SSS} pattern and a precision threshold of {@link ChronoUnit#MINUTES}, + * this method will combine sequences associated with {@code yyyy-MM-dd'T'HH:mm:} into a single sequence, + * since these are consequent and effectively constant sequences. *

* *

Example

* - *

- * The {@code [MM-dd] HH:mm} pattern will result in following sequences: - *

- * - *
{@code
-     * [
-     *     static(literal="["),
-     *     dynamic(pattern="MM", precision=MONTHS),
-     *     static(literal="-"),
-     *     dynamic(pattern="dd", precision=DAYS),
-     *     static(literal="]"),
-     *     static(literal=" "),
-     *     dynamic(pattern="HH", precision=HOURS),
-     *     static(literal=":"),
-     *     dynamic(pattern="mm", precision=MINUTES)
-     * ]
-     * }
- * - *

- * The above sequencing implies creation of 9 {@link AbstractFormatter}s. - * This method transforms it to the following: - *

- * - *
{@code
-     * [
-     *     static(literal="["),
-     *     dynamic(pattern="MM", precision=MONTHS),
-     *     static(literal="-"),
-     *     dynamic(pattern="dd", precision=DAYS),
-     *     static(literal="] "),
-     *     dynamic(pattern="HH", precision=HOURS),
-     *     static(literal=":"),
-     *     dynamic(pattern="mm", precision=MINUTES)
-     * ]
-     * }
- * - *

- * The above sequencing implies creation of 8 {@link AbstractFormatter}s. - *

- * - * @param sequences sequences to be transformed - * @return transformed sequencing where consequent static sequences are merged - */ - private static List mergeConsequentStaticPatternSequences(final List sequences) { - - // Short-circuit if there is nothing to merge - if (sequences.size() < 2) { - return sequences; - } - - final List mergedSequences = new ArrayList<>(); - final List accumulatedSequences = new ArrayList<>(); - for (final PatternSequence sequence : sequences) { - - // Spotted a static sequence? Stage it for merging. - if (sequence instanceof StaticPatternSequence) { - accumulatedSequences.add((StaticPatternSequence) sequence); - } - - // Spotted a dynamic sequence. - // Merge the accumulated static sequences, and then append the dynamic sequence. - else { - mergeConsequentStaticPatternSequences(mergedSequences, accumulatedSequences); - mergedSequences.add(sequence); - } - } - - // Merge leftover static sequences - mergeConsequentStaticPatternSequences(mergedSequences, accumulatedSequences); - return mergedSequences; - } - - private static void mergeConsequentStaticPatternSequences( - final List mergedSequences, final List accumulatedSequences) { - mergeAccumulatedSequences(mergedSequences, accumulatedSequences, () -> { - final String literal = accumulatedSequences.stream() - .map(sequence -> sequence.literal) - .collect(Collectors.joining()); - return new StaticPatternSequence(literal); - }); - } - - /** - * Merges the sequences in between the first and the last found dynamic (i.e., non-constant) sequences. - * - *

- * For example, given the {@code ss.SSS} pattern – where {@code ss} and {@code SSS} is effectively not constant, yet {@code .} is – this method will combine it into a single dynamic sequence. - * Because, as demonstrated in {@code DateTimeFormatterSequencingBenchmark}, formatting {@code ss.SSS} is approximately 20% faster than formatting first {@code ss}, then manually appending a {@code .}, and then formatting {@code SSS}. - *

- * - *

Example

- * - *

- * Assume {@link #mergeConsequentStaticPatternSequences(List)} produced the following: - *

- * *
{@code
      * [
      *     dynamic(pattern="yyyy", precision=YEARS),
@@ -395,115 +314,7 @@ private static void mergeConsequentStaticPatternSequences(
      *     static(literal=":"),
      *     dynamic(pattern="ss", precision=SECONDS),
      *     static(literal="."),
-     *     dynamic(pattern="SSS", precision=MILLISECONDS),
-     *     dynamic(pattern="X", precision=HOURS),
-     * ]
-     * }
- * - *

- * For a threshold precision of {@link ChronoUnit#MINUTES}, this sequencing effectively translates to two {@link DateTimeFormatter#formatTo(TemporalAccessor, Appendable)} invocations for each {@link #formatTo(StringBuilder, Instant)} call: one for {@code ss}, and another one for {@code SSS}. - * This method transforms the above sequencing into the following: - *

- * - *
{@code
-     * [
-     *     dynamic(pattern="yyyy", precision=YEARS),
-     *     static(literal="-"),
-     *     dynamic(pattern="MM", precision=MONTHS),
-     *     static(literal="-"),
-     *     dynamic(pattern="dd", precision=DAYS),
-     *     static(literal="T"),
-     *     dynamic(pattern="HH", precision=HOURS),
-     *     static(literal=":"),
-     *     dynamic(pattern="mm", precision=MINUTES),
-     *     static(literal=":"),
-     *     composite(
-     *         sequences=[
-     *             dynamic(pattern="ss", precision=SECONDS),
-     *             static(literal="."),
-     *             dynamic(pattern="SSS", precision=MILLISECONDS)
-     *         ],
-     *         precision=MILLISECONDS),
-     *     dynamic(pattern="X", precision=HOURS),
-     * ]
-     * }
- * - *

- * The resultant sequencing effectively translates to a single {@link DateTimeFormatter#formatTo(TemporalAccessor, Appendable)} invocation for each {@link #formatTo(StringBuilder, Instant)} call: only one fore {@code ss.SSS}. - *

- * - * @param sequences sequences, preferable produced by {@link #mergeConsequentStaticPatternSequences(List)}, to be transformed - * @param precisionThreshold a precision threshold to determine dynamic (i.e., non-constant) sequences - * @return transformed sequencing where sequences in between the first and the last found dynamic (i.e., non-constant) sequences are merged - */ - private static List mergeDynamicSequences( - final List sequences, final ChronoUnit precisionThreshold) { - - // Locate the first and the last dynamic (i.e., non-constant) sequence indices - int firstDynamicSequenceIndex = -1; - int lastDynamicSequenceIndex = -1; - for (int sequenceIndex = 0; sequenceIndex < sequences.size(); sequenceIndex++) { - final PatternSequence sequence = sequences.get(sequenceIndex); - final boolean constant = sequence.isConstantForDurationOf(precisionThreshold); - if (!constant) { - if (firstDynamicSequenceIndex < 0) { - firstDynamicSequenceIndex = sequenceIndex; - } - lastDynamicSequenceIndex = sequenceIndex; - } - } - - // Short-circuit if there are less than 2 dynamic sequences - if (firstDynamicSequenceIndex < 0 || firstDynamicSequenceIndex == lastDynamicSequenceIndex) { - return sequences; - } - - // Merge dynamic sequences - final List mergedSequences = new ArrayList<>(); - if (firstDynamicSequenceIndex > 0) { - mergedSequences.addAll(sequences.subList(0, firstDynamicSequenceIndex)); - } - final PatternSequence mergedDynamicSequence = new CompositePatternSequence( - sequences.subList(firstDynamicSequenceIndex, lastDynamicSequenceIndex + 1)); - mergedSequences.add(mergedDynamicSequence); - if ((lastDynamicSequenceIndex + 1) < sequences.size()) { - mergedSequences.addAll(sequences.subList(lastDynamicSequenceIndex + 1, sequences.size())); - } - return mergedSequences; - } - - /** - * Merges sequences that are consequent and effectively constant for the provided precision threshold. - * - *

- * For example, given the {@code yyyy-MM-dd'T'HH:mm:ss.SSS} pattern and a precision threshold of {@link ChronoUnit#MINUTES}, this method will combine sequences associated with {@code yyyy-MM-dd'T'HH:mm:} into a single sequence, since these are consequent and effectively constant sequences. - *

- * - *

Example

- * - *

- * Assume {@link #mergeDynamicSequences(List, ChronoUnit)} produced the following: - *

- * - *
{@code
-     * [
-     *     dynamic(pattern="yyyy", precision=YEARS),
-     *     static(literal="-"),
-     *     dynamic(pattern="MM", precision=MONTHS),
-     *     static(literal="-"),
-     *     dynamic(pattern="dd", precision=DAYS),
-     *     static(literal="T"),
-     *     dynamic(pattern="HH", precision=HOURS),
-     *     static(literal=":"),
-     *     dynamic(pattern="mm", precision=MINUTES),
-     *     static(literal=":"),
-     *     composite(
-     *         sequences=[
-     *             dynamic(pattern="ss", precision=SECONDS),
-     *             static(literal="."),
-     *             dynamic(pattern="SSS", precision=MILLISECONDS)
-     *         ],
-     *         precision=MILLISECONDS),
+     *     dynamic(pattern="SSS", precision=MILLISECONDS)
      *     dynamic(pattern="X", precision=HOURS),
      * ]
      * }
@@ -515,28 +326,9 @@ private static List mergeDynamicSequences( * *
{@code
      * [
-     *     composite(
-     *         sequences=[
-     *             dynamic(pattern="yyyy", precision=YEARS),
-     *             static(literal="-"),
-     *             dynamic(pattern="MM", precision=MONTHS),
-     *             static(literal="-"),
-     *             dynamic(pattern="dd", precision=DAYS),
-     *             static(literal="T"),
-     *             dynamic(pattern="HH", precision=HOURS),
-     *             static(literal=":"),
-     *             dynamic(pattern="mm", precision=MINUTES),
-     *             static(literal=":")
-     *         ],
-     *         precision=MINUTES),
-     *     composite(
-     *         sequences=[
-     *             dynamic(pattern="ss", precision=SECONDS),
-     *             static(literal="."),
-     *             dynamic(pattern="SSS", precision=MILLISECONDS)
-     *         ],
-     *         precision=MILLISECONDS),
-     *     dynamic(pattern="X", precision=HOURS),
+     *     dynamic(pattern="yyyy-MM-dd'T'HH:mm", precision=MINUTES),
+     *     dynamic(pattern="ss.SSS", precision=MILLISECONDS),
+     *     dynamic(pattern="X", precision=MINUTES)
      * ]
      * }
* @@ -544,54 +336,32 @@ private static List mergeDynamicSequences( * The resultant sequencing effectively translates to 3 {@link AbstractFormatter}s. *

* - * @param sequences sequences, preferable produced by {@link #mergeDynamicSequences(List, ChronoUnit)}, to be transformed + * @param sequences a list of pattern formatter factories * @param precisionThreshold a precision threshold to determine effectively constant sequences - * @return transformed sequencing where sequences that are consequent and effectively constant for the provided precision threshold are merged + * @return transformed sequencing, where sequences that are effectively constant or effectively dynamic are merged. */ - private static List mergeConsequentEffectivelyConstantSequences( - final List sequences, final ChronoUnit precisionThreshold) { - - // Short-circuit if there is nothing to merge + private static List mergeFactories( + final List sequences, final ChronoUnit precisionThreshold) { if (sequences.size() < 2) { return sequences; } - - final List mergedSequences = new ArrayList<>(); - boolean accumulatorConstant = true; - final List accumulatedSequences = new ArrayList<>(); - for (final PatternSequence sequence : sequences) { - final boolean sequenceConstant = sequence.isConstantForDurationOf(precisionThreshold); - if (sequenceConstant != accumulatorConstant) { - mergeConsequentEffectivelyConstantSequences(mergedSequences, accumulatedSequences); - accumulatorConstant = sequenceConstant; + final List mergedSequences = new ArrayList<>(); + PatternFormatterFactory currentFactory = sequences.get(0); + for (int i = 1; i < sequences.size(); i++) { + PatternFormatterFactory nextFactory = sequences.get(i); + PatternFormatterFactory mergedFactory = currentFactory.tryMerge(nextFactory, precisionThreshold); + // The current factory cannot be merged with the next one. + if (mergedFactory == null) { + mergedSequences.add(currentFactory); + currentFactory = nextFactory; + } else { + currentFactory = mergedFactory; } - accumulatedSequences.add(sequence); } - - // Merge the accumulator leftover - mergeConsequentEffectivelyConstantSequences(mergedSequences, accumulatedSequences); + mergedSequences.add(currentFactory); return mergedSequences; } - private static void mergeConsequentEffectivelyConstantSequences( - final List mergedSequences, final List accumulatedSequences) { - mergeAccumulatedSequences( - mergedSequences, accumulatedSequences, () -> new CompositePatternSequence(accumulatedSequences)); - } - - private static void mergeAccumulatedSequences( - final List mergedSequences, - final List accumulatedSequences, - final Supplier mergedSequenceSupplier) { - if (accumulatedSequences.isEmpty()) { - return; - } - final PatternSequence mergedSequence = - accumulatedSequences.size() == 1 ? accumulatedSequences.get(0) : mergedSequenceSupplier.get(); - mergedSequences.add(mergedSequence); - accumulatedSequences.clear(); - } - private static long toEpochMinutes(final Instant instant) { return instant.getEpochSecond() / 60; } @@ -602,7 +372,7 @@ private static TemporalAccessor toTemporalAccessor(final Instant instant) { : java.time.Instant.ofEpochSecond(instant.getEpochSecond(), instant.getNanoOfSecond()); } - private abstract static class AbstractFormatter implements InstantPatternFormatter { + abstract static class AbstractFormatter implements InstantPatternFormatter { private final String pattern; @@ -612,7 +382,7 @@ private abstract static class AbstractFormatter implements InstantPatternFormatt private final ChronoUnit precision; - private AbstractFormatter( + AbstractFormatter( final String pattern, final Locale locale, final TimeZone timeZone, final ChronoUnit precision) { this.pattern = pattern; this.locale = locale; @@ -641,32 +411,39 @@ public TimeZone getTimeZone() { } } - abstract static class PatternSequence { + /** + * Creates an {@link InstantPatternFormatter}. + */ + abstract static class PatternFormatterFactory { final String pattern; final ChronoUnit precision; @SuppressWarnings("ReturnValueIgnored") - PatternSequence(final String pattern, final ChronoUnit precision) { + PatternFormatterFactory(final String pattern, final ChronoUnit precision) { DateTimeFormatter.ofPattern(pattern); // Validate the pattern this.pattern = pattern; this.precision = precision; } - InstantPatternFormatter createFormatter(final Locale locale, final TimeZone timeZone) { - final DateTimeFormatter dateTimeFormatter = - DateTimeFormatter.ofPattern(pattern, locale).withZone(timeZone.toZoneId()); - return new AbstractFormatter(pattern, locale, timeZone, precision) { - @Override - public void formatTo(final StringBuilder buffer, final Instant instant) { - final TemporalAccessor instantAccessor = toTemporalAccessor(instant); - dateTimeFormatter.formatTo(instantAccessor, buffer); - } - }; + abstract InstantPatternFormatter createFormatter(final Locale locale, final TimeZone timeZone); + + /** + * Tries to merge two factories. + * + * @param other A pattern formatter factory. + * @param thresholdPrecision The time interval during which the instant formatters created by this factory will + * be used. + * This prevents merging effectively constant and dynamic factories. + * @return A merged formatter factory or {@code null} if merging is not possible. + */ + @Nullable + PatternFormatterFactory tryMerge(PatternFormatterFactory other, ChronoUnit thresholdPrecision) { + return null; } - private boolean isConstantForDurationOf(final ChronoUnit thresholdPrecision) { + boolean isConstantForDurationOf(final ChronoUnit thresholdPrecision) { return precision.compareTo(thresholdPrecision) >= 0; } @@ -678,7 +455,7 @@ public boolean equals(final Object object) { if (object == null || getClass() != object.getClass()) { return false; } - PatternSequence sequence = (PatternSequence) object; + PatternFormatterFactory sequence = (PatternFormatterFactory) object; return Objects.equals(pattern, sequence.pattern) && precision == sequence.precision; } @@ -689,16 +466,16 @@ public int hashCode() { @Override public String toString() { - return String.format("<%s>%s", pattern, precision); + return getClass().getSimpleName() + "[" + "pattern='" + pattern + '\'' + ", precision=" + precision + ']'; } } - static final class StaticPatternSequence extends PatternSequence { + static final class StaticPatternFormatterFactory extends PatternFormatterFactory { private final String literal; - StaticPatternSequence(final String literal) { - super(literal.equals("'") ? "''" : ("'" + literal + "'"), ChronoUnit.FOREVER); + StaticPatternFormatterFactory(final String literal) { + super(escapeLiteral(literal), ChronoUnit.FOREVER); this.literal = literal; } @@ -711,23 +488,114 @@ public void formatTo(final StringBuilder buffer, final Instant instant) { } }; } + + @Override + @Nullable + PatternFormatterFactory tryMerge(PatternFormatterFactory other, ChronoUnit thresholdPrecision) { + // We always merge consecutive static pattern factories + if (other instanceof StaticPatternFormatterFactory) { + final StaticPatternFormatterFactory otherStatic = (StaticPatternFormatterFactory) other; + return new StaticPatternFormatterFactory(this.literal + otherStatic.literal); + } + // We also merge a static pattern factory with a DTF factory + if (other instanceof DateTimeFormatterPatternFormatterFactory) { + final DateTimeFormatterPatternFormatterFactory otherDtf = + (DateTimeFormatterPatternFormatterFactory) other; + return new DateTimeFormatterPatternFormatterFactory( + this.pattern + otherDtf.pattern, otherDtf.precision); + } + return super.tryMerge(other, thresholdPrecision); + } + + static String escapeLiteral(String literal) { + StringBuilder sb = new StringBuilder(literal.length() + 2); + boolean inSingleQuotes = false; + for (int i = 0; i < literal.length(); i++) { + char c = literal.charAt(i); + if (c == '\'') { + if (inSingleQuotes) { + sb.append("'"); + } + inSingleQuotes = false; + sb.append("''"); + } else { + if (!inSingleQuotes) { + sb.append("'"); + } + inSingleQuotes = true; + sb.append(c); + } + } + if (inSingleQuotes) { + sb.append("'"); + } + return sb.toString(); + } } - static final class DynamicPatternSequence extends PatternSequence { + /** + * Formats the pattern using {@link DateTimeFormatter}. + */ + static final class DateTimeFormatterPatternFormatterFactory extends PatternFormatterFactory { - DynamicPatternSequence(final String content) { - super(content, contentPrecision(content)); + /** + * @param simplePattern A {@link DateTimeFormatter} pattern containing a single letter. + */ + DateTimeFormatterPatternFormatterFactory(final String simplePattern) { + this(simplePattern, patternPrecision(simplePattern)); } /** - * @param content a single-letter directive content complying (e.g., {@code H}, {@code HH}, or {@code pHH}) - * @return the time precision of the directive + * @param pattern Any {@link DateTimeFormatter} pattern. + * @param precision The maximum interval of time over which this pattern is constant. */ + DateTimeFormatterPatternFormatterFactory(final String pattern, final ChronoUnit precision) { + super(pattern, precision); + } + + InstantPatternFormatter createFormatter(final Locale locale, final TimeZone timeZone) { + final DateTimeFormatter dateTimeFormatter = + DateTimeFormatter.ofPattern(pattern, locale).withZone(timeZone.toZoneId()); + return new AbstractFormatter(pattern, locale, timeZone, precision) { + @Override + public void formatTo(final StringBuilder buffer, final Instant instant) { + final TemporalAccessor instantAccessor = toTemporalAccessor(instant); + dateTimeFormatter.formatTo(instantAccessor, buffer); + } + }; + } + + @Override @Nullable - private static ChronoUnit contentPrecision(final String content) { + PatternFormatterFactory tryMerge(PatternFormatterFactory other, ChronoUnit thresholdPrecision) { + // We merge two DTF factories if they are both above or below the threshold + if (other instanceof DateTimeFormatterPatternFormatterFactory) { + final DateTimeFormatterPatternFormatterFactory otherDtf = + (DateTimeFormatterPatternFormatterFactory) other; + if (isConstantForDurationOf(thresholdPrecision) + == otherDtf.isConstantForDurationOf(thresholdPrecision)) { + ChronoUnit precision = this.precision.getDuration().compareTo(otherDtf.precision.getDuration()) < 0 + ? this.precision + : otherDtf.precision; + return new DateTimeFormatterPatternFormatterFactory(this.pattern + otherDtf.pattern, precision); + } + } + // We merge a static pattern factory + if (other instanceof StaticPatternFormatterFactory) { + final StaticPatternFormatterFactory otherStatic = (StaticPatternFormatterFactory) other; + return new DateTimeFormatterPatternFormatterFactory(this.pattern + otherStatic.pattern, this.precision); + } + return super.tryMerge(other, thresholdPrecision); + } - validateContent(content); - final String paddingRemovedContent = removePadding(content); + /** + * @param simplePattern a single-letter directive simplePattern complying (e.g., {@code H}, {@code HH}, or {@code pHH}) + * @return the time precision of the directive + */ + private static ChronoUnit patternPrecision(final String simplePattern) { + + validateContent(simplePattern); + final String paddingRemovedContent = removePadding(simplePattern); if (paddingRemovedContent.matches("[GuyY]+")) { return ChronoUnit.YEARS; @@ -769,7 +637,7 @@ else if (paddingRemovedContent.equals("S") return ChronoUnit.NANOS; } - final String message = String.format("unrecognized pattern: `%s`", content); + final String message = String.format("unrecognized pattern: `%s`", simplePattern); throw new IllegalArgumentException(message); } @@ -806,26 +674,114 @@ private static String removePadding(final String content) { } } - static final class CompositePatternSequence extends PatternSequence { + static class SecondPatternFormatterFactory extends PatternFormatterFactory { + + private final boolean printSeconds; + private final String separator; + private final int fractionalDigits; + + SecondPatternFormatterFactory(boolean printSeconds, String separator, int fractionalDigits) { + super( + createPattern(printSeconds, separator, fractionalDigits), + determinePrecision(printSeconds, fractionalDigits)); + this.printSeconds = printSeconds; + this.separator = separator; + this.fractionalDigits = fractionalDigits; + } - CompositePatternSequence(final List sequences) { - super(concatSequencePatterns(sequences), findSequenceMaxPrecision(sequences)); - // Only allow two or more sequences - if (sequences.size() < 2) { - throw new IllegalArgumentException("was expecting two or more sequences: " + sequences); + private static String createPattern(boolean printSeconds, String separator, int fractionalDigits) { + StringBuilder builder = new StringBuilder(); + if (printSeconds) { + builder.append("ss"); } + builder.append(StaticPatternFormatterFactory.escapeLiteral(separator)); + if (fractionalDigits > 0) { + builder.append(Strings.repeat("S", fractionalDigits)); + } + return builder.toString(); + } + + private static ChronoUnit determinePrecision(boolean printSeconds, int digits) { + return digits > 6 + ? ChronoUnit.NANOS + : digits > 3 + ? ChronoUnit.MICROS + : digits > 0 ? ChronoUnit.MILLIS : printSeconds ? ChronoUnit.SECONDS : ChronoUnit.FOREVER; } - @SuppressWarnings("OptionalGetWithoutIsPresent") - private static ChronoUnit findSequenceMaxPrecision(List sequences) { - return sequences.stream() - .map(sequence -> sequence.precision) - .min(Comparator.comparing(ChronoUnit::getDuration)) - .get(); + private static void formatSeconds(StringBuilder buffer, Instant instant) { + long secondsInMinute = instant.getEpochSecond() % 60L; + buffer.append((char) ((secondsInMinute / 10L) + '0')); + buffer.append((char) ((secondsInMinute % 10L) + '0')); } - private static String concatSequencePatterns(List sequences) { - return sequences.stream().map(sequence -> sequence.pattern).collect(Collectors.joining()); + private void formatFractionalDigits(StringBuilder buffer, Instant instant) { + final int offset = buffer.length(); + buffer.setLength(offset + fractionalDigits); + long value = instant.getNanoOfSecond(); + int valuePrecision = 9; + // Skip digits beyond the requested precision + while (fractionalDigits < valuePrecision) { + valuePrecision--; + value = value / 10L; + } + // Print the digits + while (0 < valuePrecision--) { + buffer.setCharAt(offset + valuePrecision, (char) ('0' + value % 10L)); + value = value / 10L; + } + } + + @Override + InstantPatternFormatter createFormatter(Locale locale, TimeZone timeZone) { + if (!printSeconds) { + return new AbstractFormatter(pattern, locale, timeZone, precision) { + @Override + public void formatTo(StringBuilder buffer, Instant instant) { + buffer.append(separator); + formatFractionalDigits(buffer, instant); + } + }; + } + if (fractionalDigits == 0) { + return new AbstractFormatter(pattern, locale, timeZone, precision) { + @Override + public void formatTo(StringBuilder buffer, Instant instant) { + formatSeconds(buffer, instant); + buffer.append(separator); + } + }; + } + return new AbstractFormatter(pattern, locale, timeZone, precision) { + @Override + public void formatTo(StringBuilder buffer, Instant instant) { + formatSeconds(buffer, instant); + buffer.append(separator); + formatFractionalDigits(buffer, instant); + } + }; + } + + @Override + @Nullable + PatternFormatterFactory tryMerge(PatternFormatterFactory other, ChronoUnit thresholdPrecision) { + // If we don't have a fractional part, we can merge a literal separator + if (other instanceof StaticPatternFormatterFactory) { + StaticPatternFormatterFactory staticOther = (StaticPatternFormatterFactory) other; + if (fractionalDigits == 0) { + return new SecondPatternFormatterFactory( + printSeconds, this.separator + staticOther.literal, fractionalDigits); + } + } + // We can always append more fractional digits + if (other instanceof SecondPatternFormatterFactory) { + SecondPatternFormatterFactory secondOther = (SecondPatternFormatterFactory) other; + if (!secondOther.printSeconds && secondOther.separator.isEmpty()) { + return new SecondPatternFormatterFactory( + printSeconds, this.separator, this.fractionalDigits + secondOther.fractionalDigits); + } + } + return super.tryMerge(other, thresholdPrecision); } } } From 69fa9cc4331759c4cede75f3a71bd73f23d02c52 Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Sat, 28 Dec 2024 19:18:09 +0100 Subject: [PATCH 02/15] Fix failing test --- .../instant/InstantPatternThreadLocalCachedFormatterTest.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternThreadLocalCachedFormatterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternThreadLocalCachedFormatterTest.java index b25fb85d741..1f94b0b9aef 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternThreadLocalCachedFormatterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternThreadLocalCachedFormatterTest.java @@ -107,7 +107,7 @@ static Object[][] getterTestCases() { } @ParameterizedTest - @ValueSource(strings = {"S", "SSSS", "SSSSS", "SSSSSS", "SSSSSSS", "SSSSSSSS", "SSSSSSSSS", "n", "N"}) + @ValueSource(strings = {"SSSS", "SSSSS", "SSSSSS", "SSSSSSS", "SSSSSSSS", "SSSSSSSSS", "n", "N"}) void ofMilliPrecision_should_fail_on_inconsistent_precision(final String subMilliPattern) { final InstantPatternDynamicFormatter dynamicFormatter = new InstantPatternDynamicFormatter(subMilliPattern, LOCALE, TIME_ZONE); From bfce29a6542e594ad035a5649d044b5a0645ef8e Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Sat, 28 Dec 2024 19:54:08 +0100 Subject: [PATCH 03/15] Apply suggestions from code review MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: Volkan Yazıcı --- .../instant/InstantPatternDynamicFormatterTest.java | 8 +++++--- .../internal/instant/InstantPatternDynamicFormatter.java | 6 +++--- 2 files changed, 8 insertions(+), 6 deletions(-) diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java index 2eea54bc000..65ad3e20c1d 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java @@ -317,9 +317,11 @@ static Stream formatterInputs(final String pattern) { private static MutableInstant randomInstant() { final MutableInstant instant = new MutableInstant(); - // In the 1970's some time zones had sub-minute offsets to UTC, e.g., Africa/Monrovia - final int startEighties = 315_532_800; - final long epochSecond = startEighties + RANDOM.nextInt(1_621_280_470 - startEighties); // 2021-05-17 21:41:10 + // In the 1970's some time zones had sub-minute offsets to UTC, e.g., Africa/Monrovia. + // We will exclude them for tests: + final long minEpochSecond = 315_532_800; // 1980-01-01 01:00:00 + final long maxEpochSecond = 1_621_280_470; // 2021-05-17 21:41:10 + final long epochSecond = RANDOM.nextLong(minEpochSecond, maxEpochSecond); final int epochSecondNano = randomNanos(); instant.initFromEpochSecond(epochSecond, epochSecondNano); return instant; diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java index 96b0def5f12..23d68a61686 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java @@ -504,7 +504,7 @@ PatternFormatterFactory tryMerge(PatternFormatterFactory other, ChronoUnit thres return new DateTimeFormatterPatternFormatterFactory( this.pattern + otherDtf.pattern, otherDtf.precision); } - return super.tryMerge(other, thresholdPrecision); + return null; } static String escapeLiteral(String literal) { @@ -585,7 +585,7 @@ PatternFormatterFactory tryMerge(PatternFormatterFactory other, ChronoUnit thres final StaticPatternFormatterFactory otherStatic = (StaticPatternFormatterFactory) other; return new DateTimeFormatterPatternFormatterFactory(this.pattern + otherStatic.pattern, this.precision); } - return super.tryMerge(other, thresholdPrecision); + return null; } /** @@ -781,7 +781,7 @@ PatternFormatterFactory tryMerge(PatternFormatterFactory other, ChronoUnit thres printSeconds, this.separator, this.fractionalDigits + secondOther.fractionalDigits); } } - return super.tryMerge(other, thresholdPrecision); + return null; } } } From 7879316ab6c81fdb7cb676ac3dfdeed906a832fe Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Sat, 28 Dec 2024 20:16:24 +0100 Subject: [PATCH 04/15] Apply review suggestions(2) --- .../InstantPatternDynamicFormatterTest.java | 51 +++--- .../InstantPatternDynamicFormatter.java | 169 ++++++++---------- 2 files changed, 97 insertions(+), 123 deletions(-) diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java index 65ad3e20c1d..ab3d8a9dbe3 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java @@ -17,6 +17,7 @@ package org.apache.logging.log4j.core.util.internal.instant; import static java.util.Arrays.asList; +import static java.util.Collections.singletonList; import static org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.sequencePattern; import static org.assertj.core.api.Assertions.assertThat; @@ -31,9 +32,10 @@ import java.util.stream.IntStream; import java.util.stream.Stream; import org.apache.logging.log4j.core.time.MutableInstant; -import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.DateTimeFormatterPatternFormatterFactory; -import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.PatternFormatterFactory; -import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.SecondPatternFormatterFactory; +import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.DateTimeFormatterPatternSequence; +import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.PatternSequence; +import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.SecondPatternSequence; +import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.StaticPatternSequence; import org.apache.logging.log4j.util.Constants; import org.junit.jupiter.params.ParameterizedTest; import org.junit.jupiter.params.provider.Arguments; @@ -45,30 +47,31 @@ class InstantPatternDynamicFormatterTest { @ParameterizedTest @MethodSource("sequencingTestCases") void sequencing_should_work( - final String pattern, - final ChronoUnit thresholdPrecision, - final List expectedSequences) { - final List actualSequences = sequencePattern(pattern, thresholdPrecision); + final String pattern, final ChronoUnit thresholdPrecision, final List expectedSequences) { + final List actualSequences = sequencePattern(pattern, thresholdPrecision); assertThat(actualSequences).isEqualTo(expectedSequences); } static List sequencingTestCases() { final List testCases = new ArrayList<>(); + // Merged constants + testCases.add(Arguments.of(":'foo',", ChronoUnit.DAYS, singletonList(new StaticPatternSequence(":foo,")))); + // `SSSX` should be treated constant for daily updates - testCases.add(Arguments.of("SSSX", ChronoUnit.DAYS, asList(pMilliSec(), pDyn("X")))); + testCases.add(Arguments.of("SSSX", ChronoUnit.DAYS, asList(pMilliSec(), pDtf("X")))); // `yyyyMMddHHmmssSSSX` instant cache updated hourly testCases.add(Arguments.of( "yyyyMMddHHmmssSSSX", ChronoUnit.HOURS, - asList(pDyn("yyyyMMddHH", ChronoUnit.HOURS), pDyn("mm"), pSec("", 3), pDyn("X")))); + asList(pDtf("yyyyMMddHH", ChronoUnit.HOURS), pDtf("mm"), pSec("", 3), pDtf("X")))); // `yyyyMMddHHmmssSSSX` instant cache updated per minute testCases.add(Arguments.of( "yyyyMMddHHmmssSSSX", ChronoUnit.MINUTES, - asList(pDyn("yyyyMMddHHmm", ChronoUnit.MINUTES), pSec("", 3), pDyn("X")))); + asList(pDtf("yyyyMMddHHmm", ChronoUnit.MINUTES), pSec("", 3), pDtf("X")))); // ISO9601 instant cache updated daily final String iso8601InstantPattern = "yyyy-MM-dd'T'HH:mm:ss.SSSX"; @@ -76,44 +79,44 @@ static List sequencingTestCases() { iso8601InstantPattern, ChronoUnit.DAYS, asList( - pDyn("yyyy'-'MM'-'dd'T'", ChronoUnit.DAYS), - pDyn("HH':'mm':'", ChronoUnit.MINUTES), + pDtf("yyyy'-'MM'-'dd'T'", ChronoUnit.DAYS), + pDtf("HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 3), - pDyn("X")))); + pDtf("X")))); // ISO9601 instant cache updated per minute testCases.add(Arguments.of( iso8601InstantPattern, ChronoUnit.MINUTES, - asList(pDyn("yyyy'-'MM'-'dd'T'HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 3), pDyn("X")))); + asList(pDtf("yyyy'-'MM'-'dd'T'HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 3), pDtf("X")))); // ISO9601 instant cache updated per second testCases.add(Arguments.of( iso8601InstantPattern, ChronoUnit.SECONDS, - asList(pDyn("yyyy'-'MM'-'dd'T'HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 3), pDyn("X")))); + asList(pDtf("yyyy'-'MM'-'dd'T'HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 3), pDtf("X")))); // Seconds and micros testCases.add(Arguments.of( - "HH:mm:ss.SSSSSS", ChronoUnit.MINUTES, asList(pDyn("HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 6)))); + "HH:mm:ss.SSSSSS", ChronoUnit.MINUTES, asList(pDtf("HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 6)))); return testCases; } - private static DateTimeFormatterPatternFormatterFactory pDyn(final String pattern) { - return new DateTimeFormatterPatternFormatterFactory(pattern); + private static DateTimeFormatterPatternSequence pDtf(final String simplePattern) { + return new DateTimeFormatterPatternSequence(simplePattern); } - private static DateTimeFormatterPatternFormatterFactory pDyn(final String pattern, final ChronoUnit precision) { - return new DateTimeFormatterPatternFormatterFactory(pattern, precision); + private static DateTimeFormatterPatternSequence pDtf(final String pattern, final ChronoUnit precision) { + return new DateTimeFormatterPatternSequence(pattern, precision); } - private static SecondPatternFormatterFactory pSec(String separator, int fractionalDigits) { - return new SecondPatternFormatterFactory(true, separator, fractionalDigits); + private static SecondPatternSequence pSec(String separator, int fractionalDigits) { + return new SecondPatternSequence(true, separator, fractionalDigits); } - private static SecondPatternFormatterFactory pMilliSec() { - return new SecondPatternFormatterFactory(false, "", 3); + private static SecondPatternSequence pMilliSec() { + return new SecondPatternSequence(false, "", 3); } @ParameterizedTest diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java index 23d68a61686..d48eab7df5c 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java @@ -48,30 +48,6 @@ *
  • Precompute and cache the output for parts that are of precision lower than or equal to {@value InstantPatternDynamicFormatter#PRECISION_THRESHOLD} (i.e., {@code yyyy-MM-dd'T'HH:mm:} and {@code X}) and cache it
  • *
  • Upon a formatting request, combine the cached outputs with the dynamic parts (i.e., {@code ss.SSS})
  • * - *

    Implementation note

    - *

    - * Formatting can actually even be made faster and garbage-free by manually formatting sub-minute precision directives as follows: - *

    - *
    {@code
    - * int offsetMillis = timeZone.getOffset(mutableInstant.getEpochMillisecond());
    - * long adjustedEpochSeconds = (instant.getEpochMillisecond() + offsetMillis) / 1000;
    - * int local_s = (int) (adjustedEpochSeconds % 60);
    - * int local_S = instant.getNanoOfSecond() / 100000000;
    - * int local_SS = instant.getNanoOfSecond() / 10000000;
    - * int local_SSS = instant.getNanoOfSecond() / 1000000;
    - * int local_SSSS = instant.getNanoOfSecond() / 100000;
    - * int local_SSSSS = instant.getNanoOfSecond() / 10000;
    - * int local_SSSSSS = instant.getNanoOfSecond() / 1000;
    - * int local_SSSSSSS = instant.getNanoOfSecond() / 100;
    - * int local_SSSSSSSS = instant.getNanoOfSecond() / 10;
    - * int local_SSSSSSSSS = instant.getNanoOfSecond();
    - * int local_n = instant.getNanoOfSecond();
    - * }
    - *

    - * Though this will require more hardcoded formatting and a change in the sequence merging strategies. - * Hence, this optimization is intentionally shelved off due to involved complexity. - * See {@code verify_manually_computed_sub_minute_precision_values()} in {@code InstantPatternDynamicFormatterTest} for a demonstration of this optimization. - *

    * * @since 2.25.0 */ @@ -165,7 +141,7 @@ private static InstantPatternFormatter createFormatter( final Instant creationInstant) { // Sequence the pattern and create associated formatters - final List sequences = sequencePattern(pattern, precisionThreshold); + final List sequences = sequencePattern(pattern, precisionThreshold); final List formatters = sequences.stream() .map(sequence -> { final InstantPatternFormatter formatter = sequence.createFormatter(locale, timeZone); @@ -222,27 +198,26 @@ public void formatTo(final StringBuilder buffer, final Instant instant) { } } - static List sequencePattern(final String pattern, final ChronoUnit precisionThreshold) { - List sequences = sequencePattern(pattern, (l, p) -> { + static List sequencePattern(final String pattern, final ChronoUnit precisionThreshold) { + List sequences = sequencePattern(pattern, (l, p) -> { switch (l) { case 's': - return new SecondPatternFormatterFactory(true, "", 0); + return new SecondPatternSequence(true, "", 0); case 'S': - return new SecondPatternFormatterFactory(false, "", p.length()); + return new SecondPatternSequence(false, "", p.length()); default: - return new DateTimeFormatterPatternFormatterFactory(p); + return new DateTimeFormatterPatternSequence(p); } }); return mergeFactories(sequences, precisionThreshold); } - static List sequencePattern( - final String pattern, - BiFunction dynamicFormatterFactoryProvider) { + private static List sequencePattern( + final String pattern, BiFunction dynamicPatternSequenceProvider) { if (pattern.isEmpty()) { return Collections.emptyList(); } - final List sequences = new ArrayList<>(); + final List sequences = new ArrayList<>(); for (int startIndex = 0; startIndex < pattern.length(); ) { final char c = pattern.charAt(startIndex); @@ -254,7 +229,7 @@ static List sequencePattern( endIndex++; } final String sequenceContent = pattern.substring(startIndex, endIndex); - final PatternFormatterFactory sequence = dynamicFormatterFactoryProvider.apply(c, sequenceContent); + final PatternSequence sequence = dynamicPatternSequenceProvider.apply(c, sequenceContent); sequences.add(sequence); startIndex = endIndex; } @@ -262,22 +237,14 @@ static List sequencePattern( // Handle single-quotes else if (c == '\'') { final int endIndex = pattern.indexOf('\'', startIndex + 1); - if (endIndex < 0) { - final String message = String.format( - "pattern ends with an incomplete string literal that started at index %d: `%s`", - startIndex, pattern); - throw new IllegalArgumentException(message); - } - final String sequenceLiteral = - (startIndex + 1) == endIndex ? "'" : pattern.substring(startIndex + 1, endIndex); - final PatternFormatterFactory sequence = new StaticPatternFormatterFactory(sequenceLiteral); + final PatternSequence sequence = getStaticPatternSequence(pattern, startIndex, endIndex); sequences.add(sequence); startIndex = endIndex + 1; } // Handle unknown literal else { - final PatternFormatterFactory sequence = new StaticPatternFormatterFactory("" + c); + final PatternSequence sequence = new StaticPatternSequence("" + c); sequences.add(sequence); startIndex++; } @@ -285,17 +252,28 @@ else if (c == '\'') { return sequences; } + private static PatternSequence getStaticPatternSequence(String pattern, int startIndex, int endIndex) { + if (endIndex < 0) { + final String message = String.format( + "pattern ends with an incomplete string literal that started at index %d: `%s`", + startIndex, pattern); + throw new IllegalArgumentException(message); + } + final String sequenceLiteral = (startIndex + 1) == endIndex ? "'" : pattern.substring(startIndex + 1, endIndex); + return new StaticPatternSequence(sequenceLiteral); + } + private static boolean isDynamicPatternLetter(final char c) { return "GuyDMLdgQqYwWEecFaBhKkHmsSAnNVvzOXxZ".indexOf(c) >= 0; } /** - * Merges sequences of formatter factories using {@link PatternFormatterFactory#tryMerge}. + * Merges pattern sequences using {@link PatternSequence#tryMerge}. * *

    * For example, given the {@code yyyy-MM-dd'T'HH:mm:ss.SSS} pattern and a precision threshold of {@link ChronoUnit#MINUTES}, - * this method will combine sequences associated with {@code yyyy-MM-dd'T'HH:mm:} into a single sequence, - * since these are consequent and effectively constant sequences. + * this method will combine pattern sequences associated with {@code yyyy-MM-dd'T'HH:mm:} into a single sequence, + * since these are consecutive and effectively constant sequences. *

    * *

    Example

    @@ -340,16 +318,16 @@ private static boolean isDynamicPatternLetter(final char c) { * @param precisionThreshold a precision threshold to determine effectively constant sequences * @return transformed sequencing, where sequences that are effectively constant or effectively dynamic are merged. */ - private static List mergeFactories( - final List sequences, final ChronoUnit precisionThreshold) { + private static List mergeFactories( + final List sequences, final ChronoUnit precisionThreshold) { if (sequences.size() < 2) { return sequences; } - final List mergedSequences = new ArrayList<>(); - PatternFormatterFactory currentFactory = sequences.get(0); + final List mergedSequences = new ArrayList<>(); + PatternSequence currentFactory = sequences.get(0); for (int i = 1; i < sequences.size(); i++) { - PatternFormatterFactory nextFactory = sequences.get(i); - PatternFormatterFactory mergedFactory = currentFactory.tryMerge(nextFactory, precisionThreshold); + PatternSequence nextFactory = sequences.get(i); + PatternSequence mergedFactory = currentFactory.tryMerge(nextFactory, precisionThreshold); // The current factory cannot be merged with the next one. if (mergedFactory == null) { mergedSequences.add(currentFactory); @@ -411,17 +389,14 @@ public TimeZone getTimeZone() { } } - /** - * Creates an {@link InstantPatternFormatter}. - */ - abstract static class PatternFormatterFactory { + abstract static class PatternSequence { final String pattern; final ChronoUnit precision; @SuppressWarnings("ReturnValueIgnored") - PatternFormatterFactory(final String pattern, final ChronoUnit precision) { + PatternSequence(final String pattern, final ChronoUnit precision) { DateTimeFormatter.ofPattern(pattern); // Validate the pattern this.pattern = pattern; this.precision = precision; @@ -430,16 +405,15 @@ abstract static class PatternFormatterFactory { abstract InstantPatternFormatter createFormatter(final Locale locale, final TimeZone timeZone); /** - * Tries to merge two factories. + * Tries to merge two pattern sequences. * - * @param other A pattern formatter factory. - * @param thresholdPrecision The time interval during which the instant formatters created by this factory will - * be used. - * This prevents merging effectively constant and dynamic factories. + * @param other A pattern sequence. + * @param thresholdPrecision A precision threshold to determine effectively constant sequences. + * This prevents merging effectively constant and dynamic pattern sequences. * @return A merged formatter factory or {@code null} if merging is not possible. */ @Nullable - PatternFormatterFactory tryMerge(PatternFormatterFactory other, ChronoUnit thresholdPrecision) { + PatternSequence tryMerge(PatternSequence other, ChronoUnit thresholdPrecision) { return null; } @@ -455,7 +429,7 @@ public boolean equals(final Object object) { if (object == null || getClass() != object.getClass()) { return false; } - PatternFormatterFactory sequence = (PatternFormatterFactory) object; + PatternSequence sequence = (PatternSequence) object; return Objects.equals(pattern, sequence.pattern) && precision == sequence.precision; } @@ -470,11 +444,11 @@ public String toString() { } } - static final class StaticPatternFormatterFactory extends PatternFormatterFactory { + static final class StaticPatternSequence extends PatternSequence { private final String literal; - StaticPatternFormatterFactory(final String literal) { + StaticPatternSequence(final String literal) { super(escapeLiteral(literal), ChronoUnit.FOREVER); this.literal = literal; } @@ -491,18 +465,16 @@ public void formatTo(final StringBuilder buffer, final Instant instant) { @Override @Nullable - PatternFormatterFactory tryMerge(PatternFormatterFactory other, ChronoUnit thresholdPrecision) { + PatternSequence tryMerge(PatternSequence other, ChronoUnit thresholdPrecision) { // We always merge consecutive static pattern factories - if (other instanceof StaticPatternFormatterFactory) { - final StaticPatternFormatterFactory otherStatic = (StaticPatternFormatterFactory) other; - return new StaticPatternFormatterFactory(this.literal + otherStatic.literal); + if (other instanceof StaticPatternSequence) { + final StaticPatternSequence otherStatic = (StaticPatternSequence) other; + return new StaticPatternSequence(this.literal + otherStatic.literal); } // We also merge a static pattern factory with a DTF factory - if (other instanceof DateTimeFormatterPatternFormatterFactory) { - final DateTimeFormatterPatternFormatterFactory otherDtf = - (DateTimeFormatterPatternFormatterFactory) other; - return new DateTimeFormatterPatternFormatterFactory( - this.pattern + otherDtf.pattern, otherDtf.precision); + if (other instanceof DateTimeFormatterPatternSequence) { + final DateTimeFormatterPatternSequence otherDtf = (DateTimeFormatterPatternSequence) other; + return new DateTimeFormatterPatternSequence(this.pattern + otherDtf.pattern, otherDtf.precision); } return null; } @@ -534,14 +506,14 @@ static String escapeLiteral(String literal) { } /** - * Formats the pattern using {@link DateTimeFormatter}. + * Creates formatters that use {@link DateTimeFormatter}. */ - static final class DateTimeFormatterPatternFormatterFactory extends PatternFormatterFactory { + static final class DateTimeFormatterPatternSequence extends PatternSequence { /** * @param simplePattern A {@link DateTimeFormatter} pattern containing a single letter. */ - DateTimeFormatterPatternFormatterFactory(final String simplePattern) { + DateTimeFormatterPatternSequence(final String simplePattern) { this(simplePattern, patternPrecision(simplePattern)); } @@ -549,7 +521,7 @@ static final class DateTimeFormatterPatternFormatterFactory extends PatternForma * @param pattern Any {@link DateTimeFormatter} pattern. * @param precision The maximum interval of time over which this pattern is constant. */ - DateTimeFormatterPatternFormatterFactory(final String pattern, final ChronoUnit precision) { + DateTimeFormatterPatternSequence(final String pattern, final ChronoUnit precision) { super(pattern, precision); } @@ -567,23 +539,22 @@ public void formatTo(final StringBuilder buffer, final Instant instant) { @Override @Nullable - PatternFormatterFactory tryMerge(PatternFormatterFactory other, ChronoUnit thresholdPrecision) { + PatternSequence tryMerge(PatternSequence other, ChronoUnit thresholdPrecision) { // We merge two DTF factories if they are both above or below the threshold - if (other instanceof DateTimeFormatterPatternFormatterFactory) { - final DateTimeFormatterPatternFormatterFactory otherDtf = - (DateTimeFormatterPatternFormatterFactory) other; + if (other instanceof DateTimeFormatterPatternSequence) { + final DateTimeFormatterPatternSequence otherDtf = (DateTimeFormatterPatternSequence) other; if (isConstantForDurationOf(thresholdPrecision) == otherDtf.isConstantForDurationOf(thresholdPrecision)) { ChronoUnit precision = this.precision.getDuration().compareTo(otherDtf.precision.getDuration()) < 0 ? this.precision : otherDtf.precision; - return new DateTimeFormatterPatternFormatterFactory(this.pattern + otherDtf.pattern, precision); + return new DateTimeFormatterPatternSequence(this.pattern + otherDtf.pattern, precision); } } // We merge a static pattern factory - if (other instanceof StaticPatternFormatterFactory) { - final StaticPatternFormatterFactory otherStatic = (StaticPatternFormatterFactory) other; - return new DateTimeFormatterPatternFormatterFactory(this.pattern + otherStatic.pattern, this.precision); + if (other instanceof StaticPatternSequence) { + final StaticPatternSequence otherStatic = (StaticPatternSequence) other; + return new DateTimeFormatterPatternSequence(this.pattern + otherStatic.pattern, this.precision); } return null; } @@ -674,13 +645,13 @@ private static String removePadding(final String content) { } } - static class SecondPatternFormatterFactory extends PatternFormatterFactory { + static class SecondPatternSequence extends PatternSequence { private final boolean printSeconds; private final String separator; private final int fractionalDigits; - SecondPatternFormatterFactory(boolean printSeconds, String separator, int fractionalDigits) { + SecondPatternSequence(boolean printSeconds, String separator, int fractionalDigits) { super( createPattern(printSeconds, separator, fractionalDigits), determinePrecision(printSeconds, fractionalDigits)); @@ -694,7 +665,7 @@ private static String createPattern(boolean printSeconds, String separator, int if (printSeconds) { builder.append("ss"); } - builder.append(StaticPatternFormatterFactory.escapeLiteral(separator)); + builder.append(StaticPatternSequence.escapeLiteral(separator)); if (fractionalDigits > 0) { builder.append(Strings.repeat("S", fractionalDigits)); } @@ -764,20 +735,20 @@ public void formatTo(StringBuilder buffer, Instant instant) { @Override @Nullable - PatternFormatterFactory tryMerge(PatternFormatterFactory other, ChronoUnit thresholdPrecision) { + PatternSequence tryMerge(PatternSequence other, ChronoUnit thresholdPrecision) { // If we don't have a fractional part, we can merge a literal separator - if (other instanceof StaticPatternFormatterFactory) { - StaticPatternFormatterFactory staticOther = (StaticPatternFormatterFactory) other; + if (other instanceof StaticPatternSequence) { + StaticPatternSequence staticOther = (StaticPatternSequence) other; if (fractionalDigits == 0) { - return new SecondPatternFormatterFactory( + return new SecondPatternSequence( printSeconds, this.separator + staticOther.literal, fractionalDigits); } } // We can always append more fractional digits - if (other instanceof SecondPatternFormatterFactory) { - SecondPatternFormatterFactory secondOther = (SecondPatternFormatterFactory) other; + if (other instanceof SecondPatternSequence) { + SecondPatternSequence secondOther = (SecondPatternSequence) other; if (!secondOther.printSeconds && secondOther.separator.isEmpty()) { - return new SecondPatternFormatterFactory( + return new SecondPatternSequence( printSeconds, this.separator, this.fractionalDigits + secondOther.fractionalDigits); } } From 07799647c5f381a9199f715b0e67bb563508c551 Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Sat, 28 Dec 2024 20:25:20 +0100 Subject: [PATCH 05/15] Improve Javadoc --- .../InstantPatternDynamicFormatter.java | 30 ++++++++++--------- 1 file changed, 16 insertions(+), 14 deletions(-) diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java index d48eab7df5c..887c7a9d1fb 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java @@ -270,30 +270,32 @@ private static boolean isDynamicPatternLetter(final char c) { /** * Merges pattern sequences using {@link PatternSequence#tryMerge}. * + *

    Example

    + * *

    - * For example, given the {@code yyyy-MM-dd'T'HH:mm:ss.SSS} pattern and a precision threshold of {@link ChronoUnit#MINUTES}, + * For example, given the {@code yyyy-MM-dd'T'HH:mm:ss.SSS} pattern, a precision threshold of {@link ChronoUnit#MINUTES} + * and the three implementations ({@link DateTimeFormatterPatternSequence}, {@link StaticPatternSequence} and + * {@link SecondPatternSequence}) from this class, * this method will combine pattern sequences associated with {@code yyyy-MM-dd'T'HH:mm:} into a single sequence, * since these are consecutive and effectively constant sequences. *

    * - *

    Example

    - * *
    {@code
          * [
    -     *     dynamic(pattern="yyyy", precision=YEARS),
    +     *     dateTimeFormatter(pattern="yyyy", precision=YEARS),
          *     static(literal="-"),
    -     *     dynamic(pattern="MM", precision=MONTHS),
    +     *     dateTimeFormatter(pattern="MM", precision=MONTHS),
          *     static(literal="-"),
    -     *     dynamic(pattern="dd", precision=DAYS),
    +     *     dateTimeFormatter(pattern="dd", precision=DAYS),
          *     static(literal="T"),
    -     *     dynamic(pattern="HH", precision=HOURS),
    +     *     dateTimeFormatter(pattern="HH", precision=HOURS),
          *     static(literal=":"),
    -     *     dynamic(pattern="mm", precision=MINUTES),
    +     *     dateTimeFormatter(pattern="mm", precision=MINUTES),
          *     static(literal=":"),
    -     *     dynamic(pattern="ss", precision=SECONDS),
    +     *     second(pattern="ss", precision=SECONDS),
          *     static(literal="."),
    -     *     dynamic(pattern="SSS", precision=MILLISECONDS)
    -     *     dynamic(pattern="X", precision=HOURS),
    +     *     second(pattern="SSS", precision=MILLISECONDS)
    +     *     dateTimeFormatter(pattern="X", precision=HOURS),
          * ]
          * }
    * @@ -304,9 +306,9 @@ private static boolean isDynamicPatternLetter(final char c) { * *
    {@code
          * [
    -     *     dynamic(pattern="yyyy-MM-dd'T'HH:mm", precision=MINUTES),
    -     *     dynamic(pattern="ss.SSS", precision=MILLISECONDS),
    -     *     dynamic(pattern="X", precision=MINUTES)
    +     *     dateTimeFormatter(pattern="yyyy-MM-dd'T'HH:mm", precision=MINUTES),
    +     *     second(pattern="ss.SSS", precision=MILLISECONDS),
    +     *     dateTimeFormatter(pattern="X", precision=MINUTES)
          * ]
          * }
    * From 148315830d367772c0d89d405be064e92045549f Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Sat, 28 Dec 2024 20:35:04 +0100 Subject: [PATCH 06/15] Miscellaneous fixes --- .../InstantPatternDynamicFormatterTest.java | 6 ++-- .../InstantPatternDynamicFormatter.java | 33 +++++++++---------- 2 files changed, 19 insertions(+), 20 deletions(-) diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java index ab3d8a9dbe3..a8b2397ddde 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java @@ -103,8 +103,8 @@ static List sequencingTestCases() { return testCases; } - private static DateTimeFormatterPatternSequence pDtf(final String simplePattern) { - return new DateTimeFormatterPatternSequence(simplePattern); + private static DateTimeFormatterPatternSequence pDtf(final String singlePattern) { + return new DateTimeFormatterPatternSequence(singlePattern); } private static DateTimeFormatterPatternSequence pDtf(final String pattern, final ChronoUnit precision) { @@ -324,7 +324,7 @@ private static MutableInstant randomInstant() { // We will exclude them for tests: final long minEpochSecond = 315_532_800; // 1980-01-01 01:00:00 final long maxEpochSecond = 1_621_280_470; // 2021-05-17 21:41:10 - final long epochSecond = RANDOM.nextLong(minEpochSecond, maxEpochSecond); + final long epochSecond = minEpochSecond + RANDOM.nextLong(maxEpochSecond - minEpochSecond); final int epochSecondNano = randomNanos(); instant.initFromEpochSecond(epochSecond, epochSecondNano); return instant; diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java index 887c7a9d1fb..702bd51dc13 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java @@ -29,7 +29,6 @@ import java.util.Objects; import java.util.TimeZone; import java.util.concurrent.atomic.AtomicReference; -import java.util.function.BiFunction; import java.util.stream.Collectors; import org.apache.logging.log4j.core.time.Instant; import org.apache.logging.log4j.core.time.MutableInstant; @@ -199,21 +198,11 @@ public void formatTo(final StringBuilder buffer, final Instant instant) { } static List sequencePattern(final String pattern, final ChronoUnit precisionThreshold) { - List sequences = sequencePattern(pattern, (l, p) -> { - switch (l) { - case 's': - return new SecondPatternSequence(true, "", 0); - case 'S': - return new SecondPatternSequence(false, "", p.length()); - default: - return new DateTimeFormatterPatternSequence(p); - } - }); + List sequences = sequencePattern(pattern); return mergeFactories(sequences, precisionThreshold); } - private static List sequencePattern( - final String pattern, BiFunction dynamicPatternSequenceProvider) { + private static List sequencePattern(final String pattern) { if (pattern.isEmpty()) { return Collections.emptyList(); } @@ -229,7 +218,17 @@ private static List sequencePattern( endIndex++; } final String sequenceContent = pattern.substring(startIndex, endIndex); - final PatternSequence sequence = dynamicPatternSequenceProvider.apply(c, sequenceContent); + final PatternSequence sequence; + switch (c) { + case 's': + sequence = new SecondPatternSequence(true, "", 0); + break; + case 'S': + sequence = new SecondPatternSequence(false, "", sequenceContent.length()); + break; + default: + sequence = new DateTimeFormatterPatternSequence(sequenceContent); + } sequences.add(sequence); startIndex = endIndex; } @@ -513,10 +512,10 @@ static String escapeLiteral(String literal) { static final class DateTimeFormatterPatternSequence extends PatternSequence { /** - * @param simplePattern A {@link DateTimeFormatter} pattern containing a single letter. + * @param singlePattern A {@link DateTimeFormatter} pattern containing a single letter. */ - DateTimeFormatterPatternSequence(final String simplePattern) { - this(simplePattern, patternPrecision(simplePattern)); + DateTimeFormatterPatternSequence(final String singlePattern) { + this(singlePattern, patternPrecision(singlePattern)); } /** From acaaa694b5b386457695971ee8f6861cd04380e7 Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Sat, 28 Dec 2024 20:43:23 +0100 Subject: [PATCH 07/15] Make `AbstractFormatter` private --- .../util/internal/instant/InstantPatternDynamicFormatter.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java index 702bd51dc13..7de3b8be5d7 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java @@ -351,7 +351,7 @@ private static TemporalAccessor toTemporalAccessor(final Instant instant) { : java.time.Instant.ofEpochSecond(instant.getEpochSecond(), instant.getNanoOfSecond()); } - abstract static class AbstractFormatter implements InstantPatternFormatter { + private abstract static class AbstractFormatter implements InstantPatternFormatter { private final String pattern; From 60e90022de36e566d41ae65bae9814ce0a3004f4 Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Sat, 28 Dec 2024 20:46:15 +0100 Subject: [PATCH 08/15] Remove Java 17 method calls --- .../instant/InstantPatternDynamicFormatterTest.java | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java index a8b2397ddde..f7c100ca650 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java @@ -322,9 +322,9 @@ private static MutableInstant randomInstant() { final MutableInstant instant = new MutableInstant(); // In the 1970's some time zones had sub-minute offsets to UTC, e.g., Africa/Monrovia. // We will exclude them for tests: - final long minEpochSecond = 315_532_800; // 1980-01-01 01:00:00 - final long maxEpochSecond = 1_621_280_470; // 2021-05-17 21:41:10 - final long epochSecond = minEpochSecond + RANDOM.nextLong(maxEpochSecond - minEpochSecond); + final int minEpochSecond = 315_532_800; // 1980-01-01 01:00:00 + final int maxEpochSecond = 1_621_280_470; // 2021-05-17 21:41:10 + final long epochSecond = minEpochSecond + RANDOM.nextInt(maxEpochSecond - minEpochSecond); final int epochSecondNano = randomNanos(); instant.initFromEpochSecond(epochSecond, epochSecondNano); return instant; From a44e3c96c9cd4fe47945aeec73a609316a3bc277 Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Sat, 28 Dec 2024 20:52:02 +0100 Subject: [PATCH 09/15] Final corrections --- .../InstantPatternDynamicFormatterTest.java | 28 ++++++++-------- .../InstantPatternDynamicFormatter.java | 33 +++++++++---------- 2 files changed, 30 insertions(+), 31 deletions(-) diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java index f7c100ca650..81084415ff3 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java @@ -32,7 +32,7 @@ import java.util.stream.IntStream; import java.util.stream.Stream; import org.apache.logging.log4j.core.time.MutableInstant; -import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.DateTimeFormatterPatternSequence; +import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.DynamicPatternSequence; import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.PatternSequence; import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.SecondPatternSequence; import org.apache.logging.log4j.core.util.internal.instant.InstantPatternDynamicFormatter.StaticPatternSequence; @@ -59,19 +59,19 @@ static List sequencingTestCases() { testCases.add(Arguments.of(":'foo',", ChronoUnit.DAYS, singletonList(new StaticPatternSequence(":foo,")))); // `SSSX` should be treated constant for daily updates - testCases.add(Arguments.of("SSSX", ChronoUnit.DAYS, asList(pMilliSec(), pDtf("X")))); + testCases.add(Arguments.of("SSSX", ChronoUnit.DAYS, asList(pMilliSec(), pDyn("X")))); // `yyyyMMddHHmmssSSSX` instant cache updated hourly testCases.add(Arguments.of( "yyyyMMddHHmmssSSSX", ChronoUnit.HOURS, - asList(pDtf("yyyyMMddHH", ChronoUnit.HOURS), pDtf("mm"), pSec("", 3), pDtf("X")))); + asList(pDyn("yyyyMMddHH", ChronoUnit.HOURS), pDyn("mm"), pSec("", 3), pDyn("X")))); // `yyyyMMddHHmmssSSSX` instant cache updated per minute testCases.add(Arguments.of( "yyyyMMddHHmmssSSSX", ChronoUnit.MINUTES, - asList(pDtf("yyyyMMddHHmm", ChronoUnit.MINUTES), pSec("", 3), pDtf("X")))); + asList(pDyn("yyyyMMddHHmm", ChronoUnit.MINUTES), pSec("", 3), pDyn("X")))); // ISO9601 instant cache updated daily final String iso8601InstantPattern = "yyyy-MM-dd'T'HH:mm:ss.SSSX"; @@ -79,36 +79,36 @@ static List sequencingTestCases() { iso8601InstantPattern, ChronoUnit.DAYS, asList( - pDtf("yyyy'-'MM'-'dd'T'", ChronoUnit.DAYS), - pDtf("HH':'mm':'", ChronoUnit.MINUTES), + pDyn("yyyy'-'MM'-'dd'T'", ChronoUnit.DAYS), + pDyn("HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 3), - pDtf("X")))); + pDyn("X")))); // ISO9601 instant cache updated per minute testCases.add(Arguments.of( iso8601InstantPattern, ChronoUnit.MINUTES, - asList(pDtf("yyyy'-'MM'-'dd'T'HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 3), pDtf("X")))); + asList(pDyn("yyyy'-'MM'-'dd'T'HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 3), pDyn("X")))); // ISO9601 instant cache updated per second testCases.add(Arguments.of( iso8601InstantPattern, ChronoUnit.SECONDS, - asList(pDtf("yyyy'-'MM'-'dd'T'HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 3), pDtf("X")))); + asList(pDyn("yyyy'-'MM'-'dd'T'HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 3), pDyn("X")))); // Seconds and micros testCases.add(Arguments.of( - "HH:mm:ss.SSSSSS", ChronoUnit.MINUTES, asList(pDtf("HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 6)))); + "HH:mm:ss.SSSSSS", ChronoUnit.MINUTES, asList(pDyn("HH':'mm':'", ChronoUnit.MINUTES), pSec(".", 6)))); return testCases; } - private static DateTimeFormatterPatternSequence pDtf(final String singlePattern) { - return new DateTimeFormatterPatternSequence(singlePattern); + private static DynamicPatternSequence pDyn(final String singlePattern) { + return new DynamicPatternSequence(singlePattern); } - private static DateTimeFormatterPatternSequence pDtf(final String pattern, final ChronoUnit precision) { - return new DateTimeFormatterPatternSequence(pattern, precision); + private static DynamicPatternSequence pDyn(final String pattern, final ChronoUnit precision) { + return new DynamicPatternSequence(pattern, precision); } private static SecondPatternSequence pSec(String separator, int fractionalDigits) { diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java index 7de3b8be5d7..7066e11c58d 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java @@ -227,7 +227,7 @@ private static List sequencePattern(final String pattern) { sequence = new SecondPatternSequence(false, "", sequenceContent.length()); break; default: - sequence = new DateTimeFormatterPatternSequence(sequenceContent); + sequence = new DynamicPatternSequence(sequenceContent); } sequences.add(sequence); startIndex = endIndex; @@ -273,7 +273,7 @@ private static boolean isDynamicPatternLetter(final char c) { * *

    * For example, given the {@code yyyy-MM-dd'T'HH:mm:ss.SSS} pattern, a precision threshold of {@link ChronoUnit#MINUTES} - * and the three implementations ({@link DateTimeFormatterPatternSequence}, {@link StaticPatternSequence} and + * and the three implementations ({@link DynamicPatternSequence}, {@link StaticPatternSequence} and * {@link SecondPatternSequence}) from this class, * this method will combine pattern sequences associated with {@code yyyy-MM-dd'T'HH:mm:} into a single sequence, * since these are consecutive and effectively constant sequences. @@ -473,9 +473,9 @@ PatternSequence tryMerge(PatternSequence other, ChronoUnit thresholdPrecision) { return new StaticPatternSequence(this.literal + otherStatic.literal); } // We also merge a static pattern factory with a DTF factory - if (other instanceof DateTimeFormatterPatternSequence) { - final DateTimeFormatterPatternSequence otherDtf = (DateTimeFormatterPatternSequence) other; - return new DateTimeFormatterPatternSequence(this.pattern + otherDtf.pattern, otherDtf.precision); + if (other instanceof DynamicPatternSequence) { + final DynamicPatternSequence otherDtf = (DynamicPatternSequence) other; + return new DynamicPatternSequence(this.pattern + otherDtf.pattern, otherDtf.precision); } return null; } @@ -509,12 +509,12 @@ static String escapeLiteral(String literal) { /** * Creates formatters that use {@link DateTimeFormatter}. */ - static final class DateTimeFormatterPatternSequence extends PatternSequence { + static final class DynamicPatternSequence extends PatternSequence { /** * @param singlePattern A {@link DateTimeFormatter} pattern containing a single letter. */ - DateTimeFormatterPatternSequence(final String singlePattern) { + DynamicPatternSequence(final String singlePattern) { this(singlePattern, patternPrecision(singlePattern)); } @@ -522,7 +522,7 @@ static final class DateTimeFormatterPatternSequence extends PatternSequence { * @param pattern Any {@link DateTimeFormatter} pattern. * @param precision The maximum interval of time over which this pattern is constant. */ - DateTimeFormatterPatternSequence(final String pattern, final ChronoUnit precision) { + DynamicPatternSequence(final String pattern, final ChronoUnit precision) { super(pattern, precision); } @@ -542,20 +542,20 @@ public void formatTo(final StringBuilder buffer, final Instant instant) { @Nullable PatternSequence tryMerge(PatternSequence other, ChronoUnit thresholdPrecision) { // We merge two DTF factories if they are both above or below the threshold - if (other instanceof DateTimeFormatterPatternSequence) { - final DateTimeFormatterPatternSequence otherDtf = (DateTimeFormatterPatternSequence) other; + if (other instanceof DynamicPatternSequence) { + final DynamicPatternSequence otherDtf = (DynamicPatternSequence) other; if (isConstantForDurationOf(thresholdPrecision) == otherDtf.isConstantForDurationOf(thresholdPrecision)) { ChronoUnit precision = this.precision.getDuration().compareTo(otherDtf.precision.getDuration()) < 0 ? this.precision : otherDtf.precision; - return new DateTimeFormatterPatternSequence(this.pattern + otherDtf.pattern, precision); + return new DynamicPatternSequence(this.pattern + otherDtf.pattern, precision); } } // We merge a static pattern factory if (other instanceof StaticPatternSequence) { final StaticPatternSequence otherStatic = (StaticPatternSequence) other; - return new DateTimeFormatterPatternSequence(this.pattern + otherStatic.pattern, this.precision); + return new DynamicPatternSequence(this.pattern + otherStatic.pattern, this.precision); } return null; } @@ -674,11 +674,10 @@ private static String createPattern(boolean printSeconds, String separator, int } private static ChronoUnit determinePrecision(boolean printSeconds, int digits) { - return digits > 6 - ? ChronoUnit.NANOS - : digits > 3 - ? ChronoUnit.MICROS - : digits > 0 ? ChronoUnit.MILLIS : printSeconds ? ChronoUnit.SECONDS : ChronoUnit.FOREVER; + if (digits > 6) return ChronoUnit.NANOS; + if (digits > 3) return ChronoUnit.MICROS; + if (digits > 0) return ChronoUnit.MILLIS; + return printSeconds ? ChronoUnit.SECONDS : ChronoUnit.FOREVER; } private static void formatSeconds(StringBuilder buffer, Instant instant) { From 0e8ddb3cfc445f6e6671ce06a732b8d4f7964e91 Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Sat, 28 Dec 2024 20:54:13 +0100 Subject: [PATCH 10/15] Move `escapeLiteral` to `PatternSequence` --- .../InstantPatternDynamicFormatter.java | 50 +++++++++---------- 1 file changed, 25 insertions(+), 25 deletions(-) diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java index 7066e11c58d..fd1faed86a7 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java @@ -422,6 +422,31 @@ boolean isConstantForDurationOf(final ChronoUnit thresholdPrecision) { return precision.compareTo(thresholdPrecision) >= 0; } + static String escapeLiteral(String literal) { + StringBuilder sb = new StringBuilder(literal.length() + 2); + boolean inSingleQuotes = false; + for (int i = 0; i < literal.length(); i++) { + char c = literal.charAt(i); + if (c == '\'') { + if (inSingleQuotes) { + sb.append("'"); + } + inSingleQuotes = false; + sb.append("''"); + } else { + if (!inSingleQuotes) { + sb.append("'"); + } + inSingleQuotes = true; + sb.append(c); + } + } + if (inSingleQuotes) { + sb.append("'"); + } + return sb.toString(); + } + @Override public boolean equals(final Object object) { if (this == object) { @@ -479,31 +504,6 @@ PatternSequence tryMerge(PatternSequence other, ChronoUnit thresholdPrecision) { } return null; } - - static String escapeLiteral(String literal) { - StringBuilder sb = new StringBuilder(literal.length() + 2); - boolean inSingleQuotes = false; - for (int i = 0; i < literal.length(); i++) { - char c = literal.charAt(i); - if (c == '\'') { - if (inSingleQuotes) { - sb.append("'"); - } - inSingleQuotes = false; - sb.append("''"); - } else { - if (!inSingleQuotes) { - sb.append("'"); - } - inSingleQuotes = true; - sb.append(c); - } - } - if (inSingleQuotes) { - sb.append("'"); - } - return sb.toString(); - } } /** From 2279c116199def5f8c150aae751d8adc658aa6de Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Mon, 30 Dec 2024 10:10:05 +0100 Subject: [PATCH 11/15] Fix precision detection We assume that timezones can change in the middle of a (UTC) hour, so they have a precision of minutes. --- .../InstantPatternDynamicFormatterTest.java | 82 +++++++++++++++---- .../InstantPatternDynamicFormatter.java | 34 ++++---- 2 files changed, 85 insertions(+), 31 deletions(-) diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java index 81084415ff3..7829d234aaa 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatterTest.java @@ -202,20 +202,31 @@ void should_recognize_patterns_of_second_precision(final String pattern) { assertPatternPrecision(pattern, ChronoUnit.SECONDS); } - @ParameterizedTest - @ValueSource( - strings = { + static Stream should_recognize_patterns_of_minute_precision() { + Stream stream = Stream.of( // Basics "m", "mm", + "Z", + "x", + "X", + "O", + "z", + "VV", // Mixed with other stuff "yyyy-MM-dd HH:mm", "yyyy-MM-dd'T'HH:mm", "HH:mm", + "yyyy-MM-dd HH x", + "yyyy-MM-dd'T'HH XX", // Single-quoted text containing nanosecond and millisecond directives "yyyy-MM-dd'S'HH:mm", - "yyyy-MM-dd'n'HH:mm" - }) + "yyyy-MM-dd'n'HH:mm"); + return Constants.JAVA_MAJOR_VERSION > 8 ? Stream.concat(stream, Stream.of("v")) : stream; + } + + @ParameterizedTest + @MethodSource void should_recognize_patterns_of_minute_precision(final String pattern) { assertPatternPrecision(pattern, ChronoUnit.MINUTES); } @@ -236,28 +247,71 @@ static List hourPrecisionPatterns() { "K", "k", "H", - "Z", - "x", - "X", - "O", - "z", - "VV", // Mixed with other stuff "yyyy-MM-dd HH", "yyyy-MM-dd'T'HH", - "yyyy-MM-dd HH x", - "yyyy-MM-dd'T'HH XX", "ddHH", // Single-quoted text containing nanosecond and millisecond directives "yyyy-MM-dd'S'HH", "yyyy-MM-dd'n'HH")); if (Constants.JAVA_MAJOR_VERSION > 8) { java8Patterns.add("B"); - java8Patterns.add("v"); } return java8Patterns; } + static Stream dynamic_pattern_should_correctly_determine_precision() { + // When no a precise unit is not available, uses the closest smaller unit. + return Stream.of( + Arguments.of("G", ChronoUnit.ERAS), + Arguments.of("u", ChronoUnit.YEARS), + Arguments.of("D", ChronoUnit.DAYS), + Arguments.of("M", ChronoUnit.MONTHS), + Arguments.of("L", ChronoUnit.MONTHS), + Arguments.of("d", ChronoUnit.DAYS), + Arguments.of("Q", ChronoUnit.MONTHS), + Arguments.of("q", ChronoUnit.MONTHS), + Arguments.of("Y", ChronoUnit.YEARS), + Arguments.of("w", ChronoUnit.WEEKS), + Arguments.of("W", ChronoUnit.DAYS), // The month can change in the middle of the week + Arguments.of("F", ChronoUnit.DAYS), // The month can change in the middle of the week + Arguments.of("E", ChronoUnit.DAYS), + Arguments.of("e", ChronoUnit.DAYS), + Arguments.of("c", ChronoUnit.DAYS), + Arguments.of("a", ChronoUnit.HOURS), // Let us round it down + Arguments.of("h", ChronoUnit.HOURS), + Arguments.of("K", ChronoUnit.HOURS), + Arguments.of("k", ChronoUnit.HOURS), + Arguments.of("H", ChronoUnit.HOURS), + Arguments.of("m", ChronoUnit.MINUTES), + Arguments.of("s", ChronoUnit.SECONDS), + Arguments.of("S", ChronoUnit.MILLIS), + Arguments.of("SS", ChronoUnit.MILLIS), + Arguments.of("SSS", ChronoUnit.MILLIS), + Arguments.of("SSSS", ChronoUnit.MICROS), + Arguments.of("SSSSS", ChronoUnit.MICROS), + Arguments.of("SSSSSS", ChronoUnit.MICROS), + Arguments.of("SSSSSSS", ChronoUnit.NANOS), + Arguments.of("SSSSSSSS", ChronoUnit.NANOS), + Arguments.of("SSSSSSSSS", ChronoUnit.NANOS), + Arguments.of("A", ChronoUnit.MILLIS), + Arguments.of("n", ChronoUnit.NANOS), + Arguments.of("N", ChronoUnit.NANOS), + // Time zones can change in the middle of a UTC hour (e.g. India) + Arguments.of("VV", ChronoUnit.MINUTES), + Arguments.of("z", ChronoUnit.MINUTES), + Arguments.of("O", ChronoUnit.MINUTES), + Arguments.of("X", ChronoUnit.MINUTES), + Arguments.of("x", ChronoUnit.MINUTES), + Arguments.of("Z", ChronoUnit.MINUTES)); + } + + @ParameterizedTest + @MethodSource + void dynamic_pattern_should_correctly_determine_precision(String singlePattern, ChronoUnit expectedPrecision) { + assertThat(pDyn(singlePattern).precision).isEqualTo(expectedPrecision); + } + private static void assertPatternPrecision(final String pattern, final ChronoUnit expectedPrecision) { final InstantPatternFormatter formatter = new InstantPatternDynamicFormatter(pattern, Locale.getDefault(), TimeZone.getDefault()); diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java index fd1faed86a7..14212f31cd9 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java @@ -561,34 +561,36 @@ PatternSequence tryMerge(PatternSequence other, ChronoUnit thresholdPrecision) { } /** - * @param simplePattern a single-letter directive simplePattern complying (e.g., {@code H}, {@code HH}, or {@code pHH}) + * @param singlePattern a single-letter directive singlePattern complying (e.g., {@code H}, {@code HH}, or {@code pHH}) * @return the time precision of the directive */ - private static ChronoUnit patternPrecision(final String simplePattern) { + private static ChronoUnit patternPrecision(final String singlePattern) { - validateContent(simplePattern); - final String paddingRemovedContent = removePadding(simplePattern); + validateContent(singlePattern); + final String paddingRemovedContent = removePadding(singlePattern); - if (paddingRemovedContent.matches("[GuyY]+")) { + if (paddingRemovedContent.matches("G+")) { + return ChronoUnit.ERAS; + } else if (paddingRemovedContent.matches("[uyY]+")) { return ChronoUnit.YEARS; } else if (paddingRemovedContent.matches("[MLQq]+")) { return ChronoUnit.MONTHS; - } else if (paddingRemovedContent.matches("[wW]+")) { + } else if (paddingRemovedContent.matches("w+")) { return ChronoUnit.WEEKS; - } else if (paddingRemovedContent.matches("[DdgEecF]+")) { + } else if (paddingRemovedContent.matches("[DdgEecFW]+")) { return ChronoUnit.DAYS; - } else if (paddingRemovedContent.matches("[aBhKkH]+") - // Time-zone directives - || paddingRemovedContent.matches("[ZxXOzvV]+")) { + } else if (paddingRemovedContent.matches("[aBhKkH]+")) { return ChronoUnit.HOURS; - } else if (paddingRemovedContent.contains("m")) { + } else if (paddingRemovedContent.contains("m") + // Time-zone directives + || paddingRemovedContent.matches("[ZxXOzVv]+")) { return ChronoUnit.MINUTES; } else if (paddingRemovedContent.contains("s")) { return ChronoUnit.SECONDS; } // 2 to 3 consequent `S` characters output millisecond precision - else if (paddingRemovedContent.matches("S{2,3}") + else if (paddingRemovedContent.matches("S{1,3}") // `A` (milli-of-day) outputs millisecond precision. || paddingRemovedContent.contains("A")) { return ChronoUnit.MILLIS; @@ -599,17 +601,15 @@ else if (paddingRemovedContent.matches("S{4,6}")) { return ChronoUnit.MICROS; } - // A single `S` (fraction-of-second) outputs nanosecond precision - else if (paddingRemovedContent.equals("S") - // 7 to 9 consequent `S` characters output nanosecond precision - || paddingRemovedContent.matches("S{7,9}") + // 7 to 9 consequent `S` characters output nanosecond precision + else if (paddingRemovedContent.matches("S{7,9}") // `n` (nano-of-second) and `N` (nano-of-day) always output nanosecond precision. // This is independent of how many times they occur sequentially. || paddingRemovedContent.matches("[nN]+")) { return ChronoUnit.NANOS; } - final String message = String.format("unrecognized pattern: `%s`", simplePattern); + final String message = String.format("unrecognized pattern: `%s`", singlePattern); throw new IllegalArgumentException(message); } From 756ee61ac4573f0e5121de3a73a60ed94f8b6635 Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Mon, 30 Dec 2024 10:36:06 +0100 Subject: [PATCH 12/15] Improve Javadoc of `tryMerge` --- .../InstantPatternDynamicFormatter.java | 24 +++++++++++++++++++ 1 file changed, 24 insertions(+) diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java index 14212f31cd9..c10bfff2cbb 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java @@ -408,6 +408,30 @@ abstract static class PatternSequence { /** * Tries to merge two pattern sequences. * + *

    + * If not {@link null}, the pattern sequence returned by this method must: + *

    + *
      + *
    1. Have a {@link #precision}, which is the minimum of the precisions of the two merged sequences.
    2. + *
    3. + * Create formatters that are equivalent to the concatenation of the formatters produced by the + * two merged sequences. + *
    4. + *
    + *

    + * The returned pattern sequence should try to achieve these two goals: + *

    + *
      + *
    1. + * Create formatters which are faster than the concatenation of the formatters produced by the + * two merged sequences. + *
    2. + *
    3. + * It should be {@link null} if one of the pattern sequences is effectively constant over + * {@code thresholdPrecision}, but the other one is not. + *
    4. + *
    + * * @param other A pattern sequence. * @param thresholdPrecision A precision threshold to determine effectively constant sequences. * This prevents merging effectively constant and dynamic pattern sequences. From 412baee3c61d9949266ef6032cbdf1a20cd05d99 Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Mon, 30 Dec 2024 17:03:26 +0100 Subject: [PATCH 13/15] Make benchmark JAR executable again --- log4j-perf-test/pom.xml | 15 +++++++++++++++ 1 file changed, 15 insertions(+) diff --git a/log4j-perf-test/pom.xml b/log4j-perf-test/pom.xml index 8b47178c9d4..f16edfad097 100644 --- a/log4j-perf-test/pom.xml +++ b/log4j-perf-test/pom.xml @@ -196,6 +196,21 @@ org.apache.maven.plugins maven-shade-plugin + + + generate-uber-jar + + + + + org.openjdk.jmh.Main + true + + + + + + From cb1a1591e46e57f03700e8011118a53a33f96bdc Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Mon, 30 Dec 2024 18:27:36 +0100 Subject: [PATCH 14/15] Document GC characteristics of instant formatters --- .../modules/ROOT/pages/manual/json-template-layout.adoc | 7 +++++++ .../antora/modules/ROOT/pages/manual/pattern-layout.adoc | 4 +++- 2 files changed, 10 insertions(+), 1 deletion(-) diff --git a/src/site/antora/modules/ROOT/pages/manual/json-template-layout.adoc b/src/site/antora/modules/ROOT/pages/manual/json-template-layout.adoc index 7b576daabd4..8fc7b16de4a 100644 --- a/src/site/antora/modules/ROOT/pages/manual/json-template-layout.adoc +++ b/src/site/antora/modules/ROOT/pages/manual/json-template-layout.adoc @@ -1291,6 +1291,13 @@ unit = "unit" -> ( rounded = "rounded" -> boolean ---- +[NOTE] +==== +The resolvers based on the `epochConfig` expression are garbage-free. + +The resolvers based on the `patternConfig` expression are low-garbage and generate temporary objects only once a minute. +==== + .See examples [%collapsible] ==== diff --git a/src/site/antora/modules/ROOT/pages/manual/pattern-layout.adoc b/src/site/antora/modules/ROOT/pages/manual/pattern-layout.adoc index 0e135285cad..d3f713e7942 100644 --- a/src/site/antora/modules/ROOT/pages/manual/pattern-layout.adoc +++ b/src/site/antora/modules/ROOT/pages/manual/pattern-layout.adoc @@ -1607,7 +1607,9 @@ Format modifiers to control such things as field width, padding, left, and right |<> -|Only the predefined date formats (`DEFAULT`, `ISO8601`, `UNIX`, `UNIX_MILLIS`, etc.) are garbage-free +| +The numeric formats (`UNIX` and `UNIX_MILLIS`) are garbage-free. +The remaining formats are low-garbage and only generate temporary objects once per minute. |<> From 0b198fc70df87e9757274d9cf9335be4ae27b008 Mon Sep 17 00:00:00 2001 From: "Piotr P. Karwasz" Date: Tue, 31 Dec 2024 07:59:24 +0100 Subject: [PATCH 15/15] Improve performance --- .../InstantPatternDynamicFormatter.java | 74 +++++++++++++------ 1 file changed, 52 insertions(+), 22 deletions(-) diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java index c10bfff2cbb..bb8059329ea 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/util/internal/instant/InstantPatternDynamicFormatter.java @@ -29,9 +29,10 @@ import java.util.Objects; import java.util.TimeZone; import java.util.concurrent.atomic.AtomicReference; -import java.util.stream.Collectors; +import java.util.stream.Stream; import org.apache.logging.log4j.core.time.Instant; import org.apache.logging.log4j.core.time.MutableInstant; +import org.apache.logging.log4j.util.BiConsumer; import org.apache.logging.log4j.util.Strings; import org.jspecify.annotations.Nullable; @@ -141,7 +142,7 @@ private static InstantPatternFormatter createFormatter( // Sequence the pattern and create associated formatters final List sequences = sequencePattern(pattern, precisionThreshold); - final List formatters = sequences.stream() + final InstantPatternFormatter[] formatters = sequences.stream() .map(sequence -> { final InstantPatternFormatter formatter = sequence.createFormatter(locale, timeZone); final boolean constant = sequence.isConstantForDurationOf(precisionThreshold); @@ -161,9 +162,9 @@ public void formatTo(final StringBuilder buffer, final Instant instant) { } }; }) - .collect(Collectors.toList()); + .toArray(InstantPatternFormatter[]::new); - switch (formatters.size()) { + switch (formatters.length) { // If found an empty pattern, return an empty formatter case 0: @@ -176,11 +177,24 @@ public void formatTo(final StringBuilder buffer, final Instant instant) { // If extracted a single formatter, return it as is case 1: - return formatters.get(0); + return formatters[0]; + + // Profiling shows that unrolling the generic loop boosts performance + case 2: + final InstantPatternFormatter first = formatters[0]; + final InstantPatternFormatter second = formatters[1]; + return new AbstractFormatter( + pattern, locale, timeZone, min(first.getPrecision(), second.getPrecision())) { + @Override + public void formatTo(StringBuilder buffer, Instant instant) { + first.formatTo(buffer, instant); + second.formatTo(buffer, instant); + } + }; // Combine all extracted formatters into one default: - final ChronoUnit precision = formatters.stream() + final ChronoUnit precision = Stream.of(formatters) .map(InstantFormatter::getPrecision) .min(Comparator.comparing(ChronoUnit::getDuration)) .get(); @@ -188,8 +202,8 @@ public void formatTo(final StringBuilder buffer, final Instant instant) { @Override public void formatTo(final StringBuilder buffer, final Instant instant) { // noinspection ForLoopReplaceableByForEach (avoid iterator allocation) - for (int formatterIndex = 0; formatterIndex < formatters.size(); formatterIndex++) { - final InstantPatternFormatter formatter = formatters.get(formatterIndex); + for (int formatterIndex = 0; formatterIndex < formatters.length; formatterIndex++) { + final InstantPatternFormatter formatter = formatters[formatterIndex]; formatter.formatTo(buffer, instant); } } @@ -197,6 +211,10 @@ public void formatTo(final StringBuilder buffer, final Instant instant) { } } + private static ChronoUnit min(ChronoUnit left, ChronoUnit right) { + return left.getDuration().compareTo(right.getDuration()) < 0 ? left : right; + } + static List sequencePattern(final String pattern, final ChronoUnit precisionThreshold) { List sequences = sequencePattern(pattern); return mergeFactories(sequences, precisionThreshold); @@ -672,6 +690,10 @@ private static String removePadding(final String content) { static class SecondPatternSequence extends PatternSequence { + private static final int[] POWERS_OF_TEN = { + 100_000_000, 10_000_000, 1_000_000, 100_000, 10_000, 1_000, 100, 10, 1 + }; + private final boolean printSeconds; private final String separator; private final int fractionalDigits; @@ -711,30 +733,38 @@ private static void formatSeconds(StringBuilder buffer, Instant instant) { } private void formatFractionalDigits(StringBuilder buffer, Instant instant) { - final int offset = buffer.length(); - buffer.setLength(offset + fractionalDigits); - long value = instant.getNanoOfSecond(); - int valuePrecision = 9; - // Skip digits beyond the requested precision - while (fractionalDigits < valuePrecision) { - valuePrecision--; - value = value / 10L; - } + int nanos = instant.getNanoOfSecond(); + // digits contain the first idx digits. + int digits; + // moreDigits contains the first (idx + 1) digits + int moreDigits = 0; // Print the digits - while (0 < valuePrecision--) { - buffer.setCharAt(offset + valuePrecision, (char) ('0' + value % 10L)); - value = value / 10L; + for (int idx = 0; idx < fractionalDigits; idx++) { + digits = moreDigits; + moreDigits = nanos / POWERS_OF_TEN[idx]; + buffer.append((char) ('0' + moreDigits - 10 * digits)); } } + private static void formatMillis(StringBuilder buffer, Instant instant) { + int ms = instant.getNanoOfSecond() / 1_000_000; + int cs = ms / 10; + int ds = cs / 10; + buffer.append((char) ('0' + ds)); + buffer.append((char) ('0' + cs - 10 * ds)); + buffer.append((char) ('0' + ms - 10 * cs)); + } + @Override InstantPatternFormatter createFormatter(Locale locale, TimeZone timeZone) { + final BiConsumer fractionDigitsFormatter = + fractionalDigits == 3 ? SecondPatternSequence::formatMillis : this::formatFractionalDigits; if (!printSeconds) { return new AbstractFormatter(pattern, locale, timeZone, precision) { @Override public void formatTo(StringBuilder buffer, Instant instant) { buffer.append(separator); - formatFractionalDigits(buffer, instant); + fractionDigitsFormatter.accept(buffer, instant); } }; } @@ -752,7 +782,7 @@ public void formatTo(StringBuilder buffer, Instant instant) { public void formatTo(StringBuilder buffer, Instant instant) { formatSeconds(buffer, instant); buffer.append(separator); - formatFractionalDigits(buffer, instant); + fractionDigitsFormatter.accept(buffer, instant); } }; }