Uploaded image for project: 'Log4j 2'
  1. Log4j 2
  2. LOG4J2-3087

Race in JsonTemplateLayout where a timestamp could end up unquoted

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 2.14.0, 2.14.1
    • Fix Version/s: 3.0.0, 2.15.0
    • Component/s: JsonTemplateLayout
    • Labels:
      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

            Activity

              People

              • Assignee:
                vy Volkan Yazici
                Reporter:
                klaren Anton Klarén
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: