[
https://issues.apache.org/jira/browse/LOG4J2-414?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13784042#comment-13784042
]
Remko Popma edited comment on LOG4J2-414 at 10/2/13 3:04 PM:
-------------------------------------------------------------
If the ring buffer is very small, and the application logs events faster than
the underlying appender can keep up with, the ring buffer will fill up, and
your application will slow down to the throughput speed of the appender plus
some overhead for the buffering. If you are logging a lot, it is important to
use the fastest appender possible. This is why I recommend using
RandomAccessFile appender and not flushing to disk on every event.
The Asynchronous Loggers give the most benefit in situations where you have
bursts of activity. The ring buffer should be large enough to hold all log
events generated by such a burst. The exact calculation depends on how fast the
appender is that takes events out of the buffer and how fast events are added
to the buffer during such a burst.
If your application does not have bursts, but instead has a very high sustained
logging rate, especially if the logging rate is faster than the appender can
keep up with, any queue that sits between the application and the appender will
fill up and asynchronous logging may not give you much benefit.
How big are your log files? (Based on the times you posted it sounds like you
are logging a lot...)
Is your application multi-threaded or single-threaded?
If your machine has enough memory, you could try -Xms3G -Xmx6G and the default
ring buffer size of 256*1024.
If that does not give good results, I would try synchronous logging with all
RandomAccessFile appenders and immediateFlush=false.
When your application is finished, this line will ensure that any data
remaining in the RandomAccessFile buffers is flushed to disk (async loggers
automatically flush at the end of a batch of events, but with synchronous
logging and immediateFlush=false you need to do this manually):
{{((LifeCycle) LogManager.getContext()).stop(); // shut down the logging
subsystem}}
was (Author: rem...@yahoo.com):
If the ring buffer is very small, and the application logs events faster than
the underlying appender can keep up with, the ring buffer will fill up, and
your application will slow down to the throughput speed of the appender plus
some overhead for the buffering. If you are logging a lot, it is important to
use the fastest appender possible. This is why I recommend using
RandomAccessFile appender and not flushing to disk on every event.
The Asynchronous Loggers give the most benefit in situations where you have
bursts of activity. The ring buffer should be large enough to hold all log
events generated by such a burst. The exact calculation depends on how fast the
appender is that takes events out of the buffer and how fast events are added
to the buffer during such a burst.
If your application does not have bursts, but instead has a very high sustained
logging rate, especially if the logging rate is faster than the appender can
keep up with, any queue that sits between the application and the appender will
fill up and asynchronous logging may not give you much benefit.
How big are your log files? (Based on the times you posted it sounds like you
are logging a lot...)
Is your application multi-threaded or single-threaded?
If your machine has enough memory, you could try -Xms3G -Xmx6G and the default
ring buffer size of 256*1024.
If that does not give good results, I would try synchronous logging with all
RandomAccessFile appenders and immediateFlush=false.
When your application is finished, this line will ensure that any data
remaining in the RandomAccessFile buffers is flushed to disk:
{{((LifeCycle) LogManager.getContext()).stop(); // shut down the logging
subsystem}}
> Async all loggers cause OutOfMemory error in log4j-2.0-beta9
> ------------------------------------------------------------
>
> Key: LOG4J2-414
> URL: https://issues.apache.org/jira/browse/LOG4J2-414
> Project: Log4j 2
> Issue Type: Bug
> Components: API, Core, log4j 1.2 emulation, SLF4J Bridge
> Affects Versions: 2.0-beta9
> Environment: linux core-4.0, java version: 1.7.0_17, memory: 8G,
> CPU: 2 cores, Intel (R) Xeon(R), startup options: -Xms64m -Xmx2048m
> -XX:MaxPermSixe=256m
> Reporter: Yiru Li
>
> 1. Problem description:
> The main function of my company's system is to read a file and then do
> calculation. The system has been using log4j1.2. We intend to switch to
> log4j2. The problem is found when we are doing evaluation on log4j2.
>
> Using the log4j2.xml described below , setting all loggers being synchronous,
> there is no problem to ran a 30k-row-long file through the system.
> With setting all loggers being asynchronous, there is no problem to run a
> small file (10-row-long) through the system, but the OutOfMemory error (heap
> space) is caused when the system runs a little larger file (3k-row-long). The
> error message is:" SEVERE: Exception processing: 781134
> org.apache.logging.log4j.core.async.RingBufferLogEvent@4f6f399c
> java.lang.OutOfMemoryError: Java heap space"
> Then I increased Xmx to 4048m, the error message shown is little different:
> "SEVERE: Exception processing: 775221
> org.apache.logging.log4j.core.async.RingBufferLogEvent@1c6b80a9
> java.lang.OutOfMemoryError: GC overhead limit exceeded"
> The same issue is repeated whenever the system runs a 3k-long file. I don't
> know how you can repeat this issue in your site.
>
> 2. start-up options
> -Xms64m -Xmx4048m -XX:MaxPermSize=256m -server $PARAM
> -Djava.security.egd=file:/dev/./urandom
> -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
> -Dlog4j.debug
> 3. The relevant jars which is deployed to our system:
> slf4j-api-1.6.6.jar
> log4j-slf4j-impl-2.0-beta9.jar
> log4j-1.2-api-2.0-beta9.jar
> log4j-api-2.0-beta9.jar
> log4j-core-2.0-beta9.jar
> disruptor-3.2.0.jar
> 4. the content of log4j2.xml is copied below:
> {code}
> <?xml version="1.0" encoding="UTF-8"?>
> <Configuration>
> <Appenders>
> <!-- Appender R -->
> <RollingFile name="R"
> fileName="/logs4j2/tpaeventsystem/log4j/STACBatch-Common.log"
>
> filePattern="/logs-4j2/tpaeventsystem/log4j/$${date:yyyy-MM}/STACBatch-Common-%d{MM-dd-yyyy}-%i.log.gz"
> append="true" bufferedIO="true" immediateFlush="true" >
> <PatternLayout pattern="(%d), %X{FILEID}, %X{HostName},
> STACBatch-Common, %m %t %n"/>
> <Policies>
> <SizeBasedTriggeringPolicy size="10 MB"/>
> </Policies>
> <DefaultRolloverStrategy max="50"/>
> </RollingFile>
>
> <!-- Appender FileProcessor -->
> <RollingFile name="FileProcessor"
> fileName="/logs-4j2/tpaeventsystem/log4j/STACBatch-FileProcessor.log"
>
> filePattern="/logs-4j2/tpaeventsystem/log4j/$${date:yyyy-MM}/STACBatch-FileProcessor-%d{MM-dd-yyyy}-%i.log.gz"
> append="true" bufferedIO="true" immediateFlush="true">
> <PatternLayout pattern="(%d), %X{FILEID}, %X{HostName},
> STACBatch-FileProcessor, %m %t %n"/>
> <Policies>
> <SizeBasedTriggeringPolicy size="10 MB"/>
> </Policies>
> <DefaultRolloverStrategy max="50"/>
>
> </RollingFile>
>
> <!-- Appender FTPProcessor -->
> <RollingFile name="FTPProcessor"
> fileName="/logs-4j2/tpaeventsystem/log4j/STACatch-FTPProcessor.log"
>
> filePattern="/logs-4j2/tpaeventsystem/log4j/$${date:yyyy-MM}/STACBatch-FTPProcessor-%d{MM-dd-yyyy}-%i.log.gz"
> append="true" bufferedIO="true" immediateFlush="true">
> <PatternLayout pattern="(%d), %X{HostName},
> STACBatch-FTPProcessor, %m %t %n"/>
> <Policies>
> <SizeBasedTriggeringPolicy size="10 MB"/>
> </Policies>
> <DefaultRolloverStrategy max="50"/>
> </RollingFile>
>
> <!-- Appender Email -->
> <RollingFile name="Email"
> fileName="/logs-4j2/tpaeventsystem/log4j/STACBatch-Email.log"
>
> filePattern="/logs-4j2/tpaeventsystem/log4j/$${date:yyyy-MM}/STACBatch-Email-%d{MM-dd-yyyy}-%i.log.gz"
> append="true" bufferedIO="true" immediateFlush="true">
> <PatternLayout pattern="(%d), %X{FILEID}, %X{HostName},
> STACBatch-Email, %m %t %n"/>
> <Policies>
> <SizeBasedTriggeringPolicy size="10 MB"/>
> </Policies>
> <DefaultRolloverStrategy max="50"/>
> </RollingFile>
>
> <!-- Appender Security -->
> <RollingFile name="Security"
> fileName="/logs-4j2/tpaeventsystem/log4j/STACBatch-Security.log"
>
> filePattern="/logs-4j2/tpaeventsystem/log4j/$${date:yyyy-MM}/STACBatch-Security-%d{MM-dd-yyyy}-%i.log.gz"
> append="true" bufferedIO="true" immediateFlush="true">
> <PatternLayout pattern="(%d), %X{FILEID}, %X{HostName},
> STACBatch-Security, %m %t %n"/>
> <Policies>
> <SizeBasedTriggeringPolicy size="10 MB"/>
> </Policies>
> <DefaultRolloverStrategy max="50"/>
> </RollingFile>
>
> <!-- Appender PerformanceStatus -->
> <RollingFile name="PerformanceStatus"
> fileName="/logs-4j2/tpaeventsystem/log4j/STACBatch-PerfMonitoring.log"
>
> filePattern="/logs-4j2/tpaeventsystem/log4j/$${date:yyyy-MM}/STACBatch-PerfMonitoring-%d{MM-dd-yyyy}-%i.log.gz"
> append="true" bufferedIO="true" immediateFlush="true">
> <PatternLayout pattern="(%d)|%m%n"/>
> <Policies>
> <SizeBasedTriggeringPolicy size="10 MB"/>
> </Policies>
> <DefaultRolloverStrategy max="50"/>
> </RollingFile>
>
> <!-- Appender EventSystem -->
> <RollingFile name="EventSystem"
> fileName="/logs-4j2/tpaeventsystem/log4j/STACBatch-EventSystem.log"
>
> filePattern="/logs-4j2/tpaeventsystem/log4j/$${date:yyyy-MM}/STACBatch-EventSystem-%d{MM-dd-yyyy}-%i.log.gz"
> append="true" bufferedIO="true" immediateFlush="true">
> <PatternLayout pattern="(%d), %X{FILEID}, %X{HostName},
> STACBatch-EventSystem, %m %t %n"/>
> <Policies>
> <SizeBasedTriggeringPolicy size="10 MB"/>
> </Policies>
> <DefaultRolloverStrategy max="50"/>
> </RollingFile>
> </Appenders>
>
> <Loggers>
> <Logger name="com.envisagesystems.database" level="ERROR" >
> <AppenderRef ref="R" />
> </Logger>
>
> <Logger name="com.envisagesystems.util.fileprocessor"
> level="DEBUG" >
> <AppenderRef ref="FileProcessor" />
> </Logger>
>
> <Logger
> name="com.envisagesystems.cloud.workflow.eventsystem.ftp" level="DEBUG">
> <AppenderRef ref="FTPProcessor" />
> </Logger>
>
> <Logger name="com.envisagesystems.util.ftp" level="DEBUG">
> <AppenderRef ref="FTPProcessor" />
> </Logger>
>
> <Logger name="com.envisagesystems.util.email" level="DEBUG">
> <AppenderRef ref="Email" />
> </Logger>
>
> <Logger name="com.envisagesystems.cloud.workflow.eventsystem"
> level="DEBUG" >
> <AppenderRef ref="EventSystem" />
> </Logger>
>
> <Logger name="com.envisagesystems.cloud.workflow.eventsystemmq"
> level="DEBUG" >
> <AppenderRef ref="EventSystem" />
> </Logger>
>
> <Logger
> name="com.envisagesystems.cloud.workflow.eventsystem.tiaa" level="DEBUG">
> <AppenderRef ref="EventSystem" />
> </Logger>
>
> <Logger name="com.envisagesystems.security" level="DEBUG">
> <AppenderRef ref="Security" />
> </Logger>
>
> <Logger name="com.envisagesystems.stac" level="INFO">
> <AppenderRef ref="R" />
> </Logger>
>
> <Logger name="STATUS_UPDATES" level="INFO">
> <AppenderRef ref="PerformanceStatus" />
> </Logger>
> <!-- ROOT CONFIG -->
> <Root level="DEBUG">
> <AppenderRef ref="R" />
> </Root>
> </Loggers>
> </Configuration>
> {code}
--
This message was sent by Atlassian JIRA
(v6.1#6144)
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org
