Details
-
Bug
-
Status: Closed
-
Major
-
Resolution: Fixed
-
2.14.0, 2.14.1
-
None
Description
There is a "race" when constructing a JsonTemplateLayout that can produce invalid JSON.
In the constructor of FormatResolverContext the formattedTimestampBuilder is populated with a formated, but unquoted, timestamp based on the current time. Later in FormatResolver.resolve() we check if the log event matches the current time and use the cached value to jsonWriter.writeRawString(), which can be unquoted if the layout and log event was created in the same millisecond.
Easy to reproduce with:
package org.apache.logging.log4j.layout.template.json; import org.apache.logging.log4j.core.LogEvent; import org.apache.logging.log4j.core.config.Configuration; import org.apache.logging.log4j.core.config.DefaultConfiguration; import org.junit.jupiter.api.RepeatedTest; class JsonTemplateLayoutTimestampTest { private static final Configuration CONFIGURATION = new DefaultConfiguration(); @RepeatedTest( 20 ) void test_timestamp_pattern_race() { final JsonTemplateLayout layout = JsonTemplateLayout .newBuilder() .setConfiguration(CONFIGURATION) .setEventTemplate("{\"t\":{\"$resolver\":\"timestamp\",\"pattern\":{\"format\":\"yyyy-MM-dd\"}}}") .build(); final LogEvent logEvent = LogEventFixture.createLiteLogEvents(1).get(0); final String json = layout.toSerializable(logEvent); System.out.println(json); } }
which can print
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":"2021-05-04"}
{"t":2021-05-04}
{"t":2021-05-04}
{"t":2021-05-04}
{"t":2021-05-04}
I'm working on a fix.
Attachments
Issue Links
- links to