You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by vy...@apache.org on 2021/11/01 20:46:18 UTC
[logging-log4j2] branch master updated: LOG4J2-3183 Avoid using
MutableInstant of the event as a cache key in JsonTemplateLayout.
This is an automated email from the ASF dual-hosted git repository.
vy pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
The following commit(s) were added to refs/heads/master by this push:
new f275c48 LOG4J2-3183 Avoid using MutableInstant of the event as a cache key in JsonTemplateLayout.
f275c48 is described below
commit f275c48e4aa423708efe07cebdbf17e4c3281b36
Author: Volkan Yazici <vo...@yazi.ci>
AuthorDate: Thu Oct 28 13:48:19 2021 +0200
LOG4J2-3183 Avoid using MutableInstant of the event as a cache key in JsonTemplateLayout.
---
.../template/json/resolver/TimestampResolver.java | 25 ++++---
.../template/json/util/InstantFormatter.java | 4 +-
.../log4j/layout/template/json/TestHelpers.java | 79 ++++++++++++++++++++--
.../json/resolver/TimestampResolverTest.java | 75 ++++++++++++++++++++
src/changes/changes.xml | 3 +
5 files changed, 166 insertions(+), 20 deletions(-)
diff --git a/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/resolver/TimestampResolver.java b/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/resolver/TimestampResolver.java
index c6fdb46..a2f1132 100644
--- a/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/resolver/TimestampResolver.java
+++ b/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/resolver/TimestampResolver.java
@@ -18,6 +18,7 @@ package org.apache.logging.log4j.layout.template.json.resolver;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.time.Instant;
+import org.apache.logging.log4j.core.time.MutableInstant;
import org.apache.logging.log4j.layout.template.json.JsonTemplateLayoutDefaults;
import org.apache.logging.log4j.layout.template.json.util.InstantFormatter;
import org.apache.logging.log4j.layout.template.json.util.JsonWriter;
@@ -217,7 +218,7 @@ public final class TimestampResolver implements EventResolver {
private final StringBuilder lastFormattedInstantBuffer = new StringBuilder();
- private Instant lastFormattedInstant;
+ private final MutableInstant lastFormattedInstant = new MutableInstant();
private PatternResolverContext(
final String pattern,
@@ -229,6 +230,7 @@ public final class TimestampResolver implements EventResolver {
.setTimeZone(timeZone)
.setLocale(locale)
.build();
+ lastFormattedInstant.initFromEpochSecond(-1, 0);
}
private static PatternResolverContext fromConfig(
@@ -281,14 +283,14 @@ public final class TimestampResolver implements EventResolver {
final JsonWriter jsonWriter) {
// Format timestamp if it doesn't match the last cached one.
- if (patternResolverContext.lastFormattedInstant == null ||
- !patternResolverContext.formatter.isInstantMatching(
- patternResolverContext.lastFormattedInstant,
- logEvent.getInstant())) {
+ final boolean instantMatching = patternResolverContext.formatter.isInstantMatching(
+ patternResolverContext.lastFormattedInstant,
+ logEvent.getInstant());
+ if (!instantMatching) {
// Format the timestamp.
patternResolverContext.lastFormattedInstantBuffer.setLength(0);
- patternResolverContext.lastFormattedInstant = logEvent.getInstant();
+ patternResolverContext.lastFormattedInstant.initFrom(logEvent.getInstant());
patternResolverContext.formatter.format(
patternResolverContext.lastFormattedInstant,
patternResolverContext.lastFormattedInstantBuffer);
@@ -352,7 +354,7 @@ public final class TimestampResolver implements EventResolver {
private static final int MAX_LONG_LENGTH =
String.valueOf(Long.MAX_VALUE).length();
- private Instant instant;
+ private final MutableInstant instant = new MutableInstant();
private final char[] resolution = new char[
/* integral: */ MAX_LONG_LENGTH +
@@ -361,7 +363,9 @@ public final class TimestampResolver implements EventResolver {
private int resolutionLength;
- private EpochResolutionRecord() {}
+ private EpochResolutionRecord() {
+ instant.initFromEpochSecond(-1, 0);
+ }
}
@@ -381,7 +385,7 @@ public final class TimestampResolver implements EventResolver {
0,
resolutionRecord.resolutionLength);
} else {
- resolutionRecord.instant = logEventInstant;
+ resolutionRecord.instant.initFrom(logEventInstant);
final StringBuilder stringBuilder = jsonWriter.getStringBuilder();
final int startIndex = stringBuilder.length();
resolve(logEventInstant, jsonWriter);
@@ -464,7 +468,8 @@ public final class TimestampResolver implements EventResolver {
};
private static long epochNanos(final Instant instant) {
- return 1_000_000_000L * instant.getEpochSecond() + instant.getNanoOfSecond();
+ final long nanos = Math.multiplyExact(1_000_000_000L, instant.getEpochSecond());
+ return Math.addExact(nanos, instant.getNanoOfSecond());
}
static String getName() {
diff --git a/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/util/InstantFormatter.java b/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/util/InstantFormatter.java
index 8e98636..af14929 100644
--- a/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/util/InstantFormatter.java
+++ b/log4j-layout-template-json/src/main/java/org/apache/logging/log4j/layout/template/json/util/InstantFormatter.java
@@ -222,9 +222,7 @@ public final class InstantFormatter {
private void formatInstant(
final Instant instant,
final StringBuilder stringBuilder) {
- mutableInstant.initFromEpochSecond(
- instant.getEpochSecond(),
- instant.getNanoOfSecond());
+ mutableInstant.initFrom(instant);
formatMutableInstant(mutableInstant, stringBuilder);
}
diff --git a/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/TestHelpers.java b/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/TestHelpers.java
index 04ac179..38e31fb 100644
--- a/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/TestHelpers.java
+++ b/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/TestHelpers.java
@@ -16,16 +16,24 @@
*/
package org.apache.logging.log4j.layout.template.json;
+import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.core.Layout;
import org.apache.logging.log4j.core.LogEvent;
+import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.core.config.Configuration;
+import org.apache.logging.log4j.core.config.Configurator;
import org.apache.logging.log4j.core.config.DefaultConfiguration;
+import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilder;
+import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory;
+import org.apache.logging.log4j.core.config.builder.impl.BuiltConfiguration;
+import org.apache.logging.log4j.core.test.appender.ListAppender;
import org.apache.logging.log4j.layout.template.json.util.JsonReader;
import org.apache.logging.log4j.layout.template.json.util.JsonWriter;
import org.apache.logging.log4j.layout.template.json.util.MapAccessor;
import java.util.LinkedHashMap;
import java.util.Map;
+import java.util.function.BiConsumer;
import java.util.function.Consumer;
public final class TestHelpers {
@@ -48,14 +56,16 @@ public final class TestHelpers {
return (Map<String, Object>) JsonReader.read(json);
}
- public static synchronized String writeJson(final Object value) {
- final StringBuilder stringBuilder = JSON_WRITER.getStringBuilder();
- stringBuilder.setLength(0);
- try {
- JSON_WRITER.writeValue(value);
- return stringBuilder.toString();
- } finally {
+ public static String writeJson(final Object value) {
+ synchronized (JSON_WRITER) {
+ final StringBuilder stringBuilder = JSON_WRITER.getStringBuilder();
stringBuilder.setLength(0);
+ try {
+ JSON_WRITER.writeValue(value);
+ return stringBuilder.toString();
+ } finally {
+ stringBuilder.setLength(0);
+ }
}
}
@@ -88,4 +98,59 @@ public final class TestHelpers {
return map;
}
+ /**
+ * Provides a configuration using the given JSON event template to the given consumer.
+ * <p>
+ * A {@link ListAppender} (named {@code List}) wrapping the layout is used to store the log events.
+ * The root logger level is set to {@link Level#ALL}.
+ * </p>
+ * @param configName a configuration name
+ * @param eventTemplate a JSON template
+ * @param consumer a consumer accepting the created logger context and the list appender
+ */
+ public static void withContextFromTemplate(
+ final String configName,
+ final Object eventTemplate,
+ final BiConsumer<LoggerContext, ListAppender> consumer) {
+
+ // Create the configuration builder.
+ final ConfigurationBuilder<BuiltConfiguration> configBuilder = ConfigurationBuilderFactory
+ .newConfigurationBuilder()
+ .setStatusLevel(Level.ERROR)
+ .setConfigurationName(configName);
+
+ // Create the configuration.
+ final String eventTemplateJson = writeJson(eventTemplate);
+ final String appenderName = "List";
+ Configuration config = configBuilder
+ .add(configBuilder
+ .newAppender(appenderName, "List")
+ .addAttribute("raw", true)
+ .add(configBuilder
+ .newLayout("JsonTemplateLayout")
+ .addAttribute(
+ "eventTemplate",
+ eventTemplateJson)))
+ .add(configBuilder
+ .newRootLogger(Level.ALL)
+ .add(configBuilder.newAppenderRef(appenderName)))
+ .build(false);
+
+ // Initialize the configuration and pass it to the consumer.
+ try (final LoggerContext loggerContext = Configurator.initialize(config)) {
+ final ListAppender appender = loggerContext.getConfiguration().getAppender("List");
+ consumer.accept(loggerContext, appender);
+ }
+
+ }
+
+ public static void uncheckedSleep(final long millis) {
+ try {
+ Thread.sleep(millis);
+ } catch (InterruptedException ignored) {
+ Thread.currentThread().interrupt();
+ throw new RuntimeException("interrupted");
+ }
+ }
+
}
diff --git a/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/resolver/TimestampResolverTest.java b/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/resolver/TimestampResolverTest.java
new file mode 100644
index 0000000..585e6c0
--- /dev/null
+++ b/log4j-layout-template-json/src/test/java/org/apache/logging/log4j/layout/template/json/resolver/TimestampResolverTest.java
@@ -0,0 +1,75 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache license, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the license for the specific language governing permissions and
+ * limitations under the license.
+ */
+package org.apache.logging.log4j.layout.template.json.resolver;
+
+import org.apache.logging.log4j.Logger;
+import org.assertj.core.api.Assertions;
+import org.junit.jupiter.api.Test;
+
+import java.nio.charset.StandardCharsets;
+import java.util.List;
+import java.util.stream.Collectors;
+
+import static org.apache.logging.log4j.layout.template.json.TestHelpers.*;
+
+class TimestampResolverTest {
+
+ /**
+ * @see <a href="https://issues.apache.org/jira/browse/LOG4J2-3183">LOG4J2-3183</a>
+ */
+ @Test
+ void epoch_nanos_should_not_overlap() {
+
+ // Create the template.
+ final Object eventTemplate = asMap(
+ "$resolver", "timestamp",
+ "epoch", asMap("unit", "nanos"));
+
+ // Create the logging context.
+ withContextFromTemplate("TimestampResolverTest", eventTemplate, (loggerContext, appender) -> {
+
+ // Log some.
+ final Logger logger = loggerContext.getLogger(TimestampResolverTest.class);
+ final int logEventCount = 5;
+ for (int logEventIndex = 0; logEventIndex < logEventCount; logEventIndex++) {
+ if (logEventIndex > 0) {
+ uncheckedSleep(1);
+ }
+ logger.info("message #{}", logEventIndex);
+ }
+
+ // Read logged events.
+ final List<Long> logEvents = appender
+ .getData()
+ .stream()
+ .map(jsonBytes -> {
+ final String json = new String(jsonBytes, StandardCharsets.UTF_8);
+ return (long) readJson(json);
+ })
+ .collect(Collectors.toList());
+
+ // Verify logged events.
+ Assertions
+ .assertThat(logEvents)
+ .hasSize(logEventCount)
+ .doesNotHaveDuplicates();
+
+ });
+
+ }
+
+}
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index a167fc5..b4a7f6d 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -237,6 +237,9 @@
based on performance improvements in modern Java releases.
</action>
<!-- FIXES -->
+ <action issue="LOG4J2-3183" dev="vy" type="fix">
+ Avoid using MutableInstant of the event as a cache key in JsonTemplateLayout.
+ </action>
<action issue="LOG4J2-2829" dev="vy" type="fix">
SocketAppender should propagate failures when reconnection fails.
</action>