You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by "Remko Popma (JIRA)" <ji...@apache.org> on 2017/01/07 13:54:58 UTC

[jira] [Resolved] (LOG4J2-1769) JsonLayout Throwing Exceptions And Producing Broken Logs

     [ https://issues.apache.org/jira/browse/LOG4J2-1769?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Remko Popma resolved LOG4J2-1769.
---------------------------------
       Resolution: Fixed
    Fix Version/s: 2.8

This issue is caused by missing synchronization in the {{AbstractLayout::writeTo}} method, and impacts all layouts other than PatternLayout and GelfLayout (which do not use this method).

This is now fixed in master (commit 2f8b665). Please verify and close.

You can work around the problem by using Async Loggers: this ensures the appender and layout logic is only executed by a single thread, even when multiple application threads are logging.

> JsonLayout Throwing Exceptions And Producing Broken Logs
> --------------------------------------------------------
>
>                 Key: LOG4J2-1769
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-1769
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Layouts
>    Affects Versions: 2.7
>         Environment: All Platforms
>            Reporter: Brandon Goodin
>            Assignee: Remko Popma
>             Fix For: 2.8
>
>         Attachments: JSONLayoutIssuesTest.java, RequestStatistic.java, log4j2.xml
>
>
> In a multithreaded environment JsonLayout is throwing exceptions and producing fragmented logs. We were able to produce a test that demonstrates this. The following exceptions and broken logging are being seen.
> {code:title=IllegalArgumentException}
> 2017-01-06 16:57:59,173 Thread-98 ERROR An exception occurred processing Appender stdout java.lang.IllegalArgumentException
> 	at java.nio.Buffer.position(Buffer.java:244)
> 	at java.nio.HeapByteBuffer.put(HeapByteBuffer.java:191)
> 	at org.apache.logging.log4j.core.layout.AbstractLayout.writeTo(AbstractLayout.java:179)
> 	at org.apache.logging.log4j.core.layout.AbstractLayout.encode(AbstractLayout.java:160)
> 	at org.apache.logging.log4j.core.layout.AbstractLayout.encode(AbstractLayout.java:36)
> 	at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:176)
> 	at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:169)
> 	at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:160)
> 	at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
> 	at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
> 	at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
> 	at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:447)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:432)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:416)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:402)
> 	at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)
> 	at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146)
> 	at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2091)
> 	at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:1988)
> 	at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1960)
> 	at org.apache.logging.log4j.spi.AbstractLogger.info(AbstractLogger.java:1297)
> 	at org.apache.logging.log4j.JSONLayoutIssuesTest$LoggingThread.run(JSONLayoutIssuesTest.java:54)
> {code}
> {code:title=BufferOverflowException}
> 2017-01-06 16:57:59,194 Thread-99 ERROR An exception occurred processing Appender stdout java.nio.BufferOverflowException
> 	at java.nio.HeapByteBuffer.put(HeapByteBuffer.java:189)
> 	at org.apache.logging.log4j.core.layout.AbstractLayout.writeTo(AbstractLayout.java:179)
> 	at org.apache.logging.log4j.core.layout.AbstractLayout.encode(AbstractLayout.java:160)
> 	at org.apache.logging.log4j.core.layout.AbstractLayout.encode(AbstractLayout.java:36)
> 	at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:176)
> 	at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:169)
> 	at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:160)
> 	at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
> 	at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
> 	at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
> 	at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:447)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:432)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:416)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:402)
> 	at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)
> 	at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146)
> 	at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2091)
> 	at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:1971)
> 	at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1829)
> 	at org.apache.logging.log4j.spi.AbstractLogger.info(AbstractLogger.java:1287)
> 	at org.apache.logging.log4j.JSONLayoutIssuesTest$LoggingThread.run(JSONLayoutIssuesTest.java:53)
> {code}
> {code:title=BrokenLogs}
> {"timeMillis":1483743479195,"thread":"Thread-49","level":"INFO","loggerName":"org.apache.logging.log4j.JSONLayoutIssuesTest","message":"This is simple text.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":61,"threadPriority":5}
> {"timeMillis":1483743479195,"thread":"Thread-42","level":"INFO","loggerName":"org.apache.logging.log4j.JSONLayoutIssuesTest","message":"This is simple text.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":54,"threadPriority":5}
> hreadPriority":5}
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org