[
https://issues.apache.org/jira/browse/LOG4J2-2791?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Johan updated LOG4J2-2791:
--------------------------
Description:
The introduction of the instant timestamp caused a regression in the ordeirng
of the timestamp as follows:
{noformat}
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
}
{noformat}
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.
was:
The introduction of the instant timestamp caused a regression in the ordeirng
of the timestamp as follows:
{noformat}
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
}
{noformat}
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 consant is used ofr
EL_INSTANT instead of the Json constant, where the constant differ in case,
which is relevant to the jackson serializer, leaving "instant" unsorted, and
"Instant" not found.
> Timestamp handling ordering regression in JsonLayout between 2.10.0 and 2.11.0
> ------------------------------------------------------------------------------
>
> Key: LOG4J2-2791
> URL: https://issues.apache.org/jira/browse/LOG4J2-2791
> Project: Log4j 2
> Issue Type: Bug
> Reporter: Johan
> Priority: Major
> Time Spent: 20m
> Remaining Estimate: 0h
>
> The introduction of the instant timestamp caused a regression in the ordeirng
> of the timestamp as follows:
> {noformat}
> 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
> }
> {noformat}
> 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.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
