[LOG4J2-437] Log4J2 Performs poorly with 500 concurrent users with Jboss 5.1.GA and JDK 6

• Type: Bug
• Status: Resolved
• Priority: Critical
• Resolution: Fixed
• Affects Version/s: 2.0-beta9
• Component/s: Appenders
• Labels: Performance

Environment

JDK : 1.6.0_18
APP Server : Jboss 5.1.0_GA
Task : Migrate from Log4J_1.2 to Log4J2
OS : Linux 5 (Virtual Machine)

• Assignee: Unassigned
• Reporter: Giri Kosuru
• Created: 26/Oct/13 02:42
• Updated: 03/Dec/13 21:24
• Resolved: 03/Dec/13 21:24

Description

Environment Details
================
JDK : 1.6.0_18
APP Server : Jboss 5.1.0_GA
Task : Migrate from Log4J_1.2 to Log4J2
OS : Linux 5 (Virtual Machine)

We are trying to upgrade from Log4J 1.2 to Log4J2 due to performance reasons. In log4j1.2, we saw thread BLOCKING and decided to go to LOG4J2. Before migration, we tested to evaluate and we found performance improvement with LOG4J2.

After full migration, when application moved to performance testing environment, we started seeing trouble with Log4j2. We saw at least 40 TPS down, with increased response times; in performance. When diagnosed, found that there is increased SWAPPING on linux and with increased IO waits (Some times 15 %).

For the same given environment and load test; application with LOG4J_1.2 code , does not have any SWAPPING and IO waits. In addition we have BAD performance with LOG4J2.

Can anyone give us pointers on what we are doing wrong ? Or there are some performance issues with LOG4J2 ?? We are stuck in between releases and if there is no help coming, we may just abandon LOG4J2. So Please I request you to look seriously and give us some pointers.

Following is the configuration for log4j2.

<?xml version="1.0" encoding="UTF-8"?>
<configuration status="trace" verbose="true">
        <appenders>
                <RollingRandomAccessFile name=“APP_1066_LOG" fileName=“/path/to/log/file-1066.log" filePattern=“/path/to/log/file-1066.log.%i" append="true" immediateFlush="false">
                        <PatternLayout>
                                <pattern>%d{ISO8601} %-5p [%t]: [%c{1}] %m%n - %X{ElapsedTime}-%X{ByteSize}- %X{uniqueID}-%X{HttpMethod}-%X{Host}-%X{URL}-%X{ClientIP}-%X{NodeID}-%X{NodeUserID}-%X{HttpCode}-%X{ApplicationCode}</pattern>
                        </PatternLayout>
                        <Policies>
                                <SizeBasedTriggeringPolicy size="250 MB"/>
                        </Policies>
                        <DefaultRolloverStrategy max="10"/>
                </RollingRandomAccessFile>

                <RollingRandomAccessFile name="hibernateAppender" fileName=“/path/to/log/anotherfile-1066.log" filePattern=“/path/to/log/anotherfile-1066.log.%i" append="true" immediateFlush="false">
                        <PatternLayout>
                                <pattern>%d{ISO8601} %-5p [%t]: [%c{1}] %m%n - %X{ElapsedTime}-%X{ByteSize}- %X{uniqueID}-%X{HttpMethod}-%X{Host}-%X{URL}-%X{ClientIP}-%X{NodeID}-%X{NodeUserID}-%X{HttpCode}-%X{ApplicationCode}</pattern>
                        </PatternLayout>
                        <Policies>
                                <SizeBasedTriggeringPolicy size="250 MB"/>
                        </Policies>
                        <DefaultRolloverStrategy max="10"/>
                </RollingRandomAccessFile>
                <Async name="ASYNC">
                        <appender-ref ref="hibernateAppender"/>
                        <appender-ref ref=“APP_1066_LOG"/>
                </Async>
        </appenders>
        <loggers>
                <root level="INFO">
                        <appender-ref ref="ASYNC"/>
                </root>
        <!-- ============================== -->
        <!-- Various loggers -->
        <!-- ============================== -->

        <logger name="org.hibernate" additivity="false" level="INFO">
                <appender-ref ref="hibernateAppender" />
        </logger>

        <logger name="org.springframework.orm.hibernate3" additivity="false" level="INFO">
                <appender-ref ref="hibernateAppender" />
        </logger>

        <logger name="org.hibernate.SQL" level="INFO">
                <appender-ref ref="hibernateAppender" />
        </logger>

        </loggers>
</configuration>