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

Timestamp handling ordering regression in JsonLayout between 2.10.0 and 2.11.0

VotersWatch issueWatchersLinkCloneUpdate Comment AuthorReplace String in CommentUpdate Comment VisibilityDelete Comments
    XMLWordPrintableJSON

Details

    • Bug
    • Status: Closed
    • Major
    • Resolution: Fixed
    • None
    • 2.13.2
    • None
    • None

    Description

      The introduction of the instant timestamp caused a regression in the ordeirng of the timestamp as follows:

      2.10.0:
      {
        "timeMillis" : 1582633940829,
        "thread" : "main",
        "level" : "INFO",
        "loggerName" : "example",
        "message" : "Example log-entry",
        "endOfBatch" : false,
        "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",
        "threadId" : 1,
        "threadPriority" : 5
      }
      
      2.11.0:
      {
        "thread" : "main",
        "level" : "INFO",
        "loggerName" : "example",
        "message" : "Example log-entry",
        "endOfBatch" : false,
        "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",
        "instant" : {
          "epochSecond" : 1582634065,
          "nanoOfSecond" : 603815000
        },
        "threadId" : 1,
        "threadPriority" : 5
      }
      
      3.0.0-SNAPSHOT (and expected behaviour):
      {
        "instant" : {
          "epochSecond" : 1582711040,
          "nanoOfSecond" : 521000000
        },
        "thread" : "main",
        "level" : "INFO",
        "loggerName" : "example",
        "message" : "Example log-entry",
        "endOfBatch" : false,
        "loggerFqcn" : "org.apache.logging.log4j.spi.AbstractLogger",
        "threadId" : 1,
        "threadPriority" : 5
      }
      
      

      As can be seen, the instant field does not sort near the start of the event, as the code appears to intend (and how it works on master). This causes issues for us in log aggregation where large events do not look unique (due to large messages, which sort before the instant)

      The problem is in LogEventJsonMixIn.java where an XML constant is used of EL_INSTANT instead of the Json constant, where the constant differs in case, which is relevant to the jackson serializer, leaving "instant" unsorted, and "Instant" not found.

      Attachments

        Activity

          This comment will be Viewable by All Users Viewable by All Users
          Cancel

          People

            Unassigned Unassigned
            Karlberg Johan Karlberg
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Time Tracking

                Estimated:
                Original Estimate - Not Specified
                Not Specified
                Remaining:
                Remaining Estimate - 0h
                0h
                Logged:
                Time Spent - 0.5h
                0.5h

                Slack

                  Issue deployment