[LOG4J2-414] Async all loggers cause OutOfMemory error in log4j-2.0-beta9

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Abandoned
• Affects Version/s: 2.0-beta9
• Component/s: API, Core, Log4j 1.2 bridge, SLF4J Bridge

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

• Assignee: Unassigned
• Reporter: Yiru Li
• Created: 01/Oct/13 14:37
• Updated: 03/Nov/13 14:21
• Resolved: 03/Nov/13 14:21

Description

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:

<?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>