You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-user@logging.apache.org by Strong Su <lo...@gmail.com> on 2015/12/10 10:09:19 UTC

Re: Bizarre performance in log4j2

Hello everyone,
We re-test log4j2's performance in our system from the very beginning. In
our case, there two factors which will decrease the performance heavily.
1. %c or %class
    As Remko said, the information of location(you can see the log4j2.xml
above)  will hurt async logger badly. And when I remove it, the performance
returns normal.
2. ringBuffer
    My mentor, Erik Fang(fmerik@gmail.com), changed the source code of
AsyncLogger and add a little counter to measure the status of ringBuffer.
When a request came, the counter will plus 1 if the ringBuffer is full for
that moment. And calculate the ratio(counter/requestsNum), call it
fullRatio, when all the requests are done.
    It turns out that when fullRatio becomes high, the performance(QPS)
will drop very quickly. I test it in our system and it's confirmed.
    I print a log whenever a request comes in my origin test and I change
the log's size like 10bytes, 100bytes and so on. The performance of
sync_log4j2 and async_log4j2 seemed normal(around 30k) and it's almost the
same as the performance when I don't print logs, which is great, and
fullRatio of async_log4j2 is lower than 1%. But as I increase the size of
one log(more than 1Kb) and number of threads, fullRatio can be up to more
than 8% and QPS of async_log4j2 drops to 19k and QPS of sync_log4j2 is
still 26k. As a result, we think factors, like extremely long logs and
numerous threads, which may make the speed of disruptor's consumer(appender
in log4j2) lower than disruptor's producer(logger in log4j2) can also
influence the performance in async_log4j2.

PS:
During the Test.
I insert a log in a http request function on server side. And I start
requests continually on client side through hundreds of threads.
I measure the performance through QPS because server has to print a log
whenever it receive a request. The time delayed by logging will influence
QPS heavily.
I continually increasing the number of client until QPS reaches the limit.
The highest QPS appears when the number of client is about 400 but QPS will
drop and fullRatio will increase after that.

Thank Erik and Remko very much.

Best Regards,
Dylan Su






On Tue, Oct 20, 2015 at 3:38 PM, Strong Su <lo...@gmail.com> wrote:

> Hello everyone,
> I take a deep look at our project and found one of our third dependencies
> was using log4j2. It is using APIs of log4j2 instead of configuration files
> but it can recognise and use my log4j2.xml.
> I wrote a simple example to illustrate how log4j2 be added in the third
> dependency.
>
> *Function_A:*
>
> public void function_A(){
>
>         LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
>
>         Configuration config = ctx.getConfiguration();
>
>         Layout layout = PatternLayout.createLayout(
>
>                 "%d{yyyy-MM-dd HH:mm:ss} [%t] %-5level %class{36} %L %M -
> %msg%xEx%n", config, null, null, true, false, null, null);
>
>
>         ConsoleAppender consoleAppender = ConsoleAppender.createAppender(
> layout, null, "SYSTEM_OUT", "consoleAppender", "false", "false");
>
>         AppenderRef consoleRef = AppenderRef.createAppenderRef(
> "consoleAppender", Level.INFO, null);
>
>         AppenderRef[] crefs = new AppenderRef[] { consoleRef };
>
>         consoleAppender.start();
>
>         config.addAppender(consoleAppender);
>
>
>
>         AsyncAppender asyncAppender = AsyncAppender.createAppender(crefs,
> null,
>
>                 true, 128, "asyncAppender", false, null, config, false);
>
>         AppenderRef accessRef = AppenderRef.createAppenderRef(
> "asyncAppender", Level.INFO, null);
>
>         AppenderRef[] arefs = new AppenderRef[] { accessRef };
>
>         asyncAppender.start();
>
>         config.addAppender(asyncAppender);
>
>
>         LoggerConfig loggerConfig = LoggerConfig.createLogger("false",
> Level.INFO, "com.TestMain", "true", arefs, null, config, null);
>
>         loggerConfig.addAppender(consoleAppender, Level.INFO, null);
>
>         config.addLogger("com.TestMain", loggerConfig);
>
>         Logger LOG = ctx.getLogger("com.TestMain");
>
> }
>
> *Log4j2.xml:*
>
> <?xml version="1.0" encoding="UTF-8"?>
>
> <Configuration status="warn">
>
>     <Appenders>
>
>         <Console name="Console" target="SYSTEM_OUT">
>
>             <PatternLayout pattern="%d %-5p %logger{36}  %msg%n"/>
>
>         </Console>
>
>     </Appenders>
>
>     <Loggers>
>
>         <Root level="info">
>
>             <AppenderRef ref="Console" />
>
>         </Root>
>
>     </Loggers>
>
> </Configuration>
>
>
> I will call the appender in function_A as appender_API, and call the
> appender from log4j2.xml as appender_XML.
>
> Through my tests to print log using logger, named LOG, from function_A. I
> found these phenomenons:
>
> 1) just use the function_A and log4j2.xml above
>
>     logs will be printed by appender_API
>
> 2) add <logger name="com.TestMain" level="info"><AppenderRef
> ref="Console"/></logger> in tag <Loggers> of log4j2.xml
>
>     logs will be printed by appender_XML twice although I have set
> additivity="false" when I create logger in function_A
>
> 3) add <logger name="com.TestMain" level="info"
> additivity="false"><AppenderRef ref="Console"/></logger> in tag <Loggers>
> of log4j2.xml
>
>     logs will be printed by appender_XML once
>
>
> How can I explain these? All I can think is that the configuration of
> logger from log4j2.xml covers the configuration from function_A. But
> I'm little confusion about the load sequence between different loggers.
>
>
> Besides, the configuration of logger named "com.TestMain" has location
> information and it sets includeLocation="true".
>
> To test async logger in log4j2, I just change <root> to <asyncRoot>
> comparing the <Loggers>'s configs of log4j2.xml from above and it turns out
> a even worse performance in my early tests. Will the combination below
> influence the performance if these two loggers print logs in the same file?
>
> 1) sync logger, async appender and includeLocation="true" to print logs
> from function_A
>
> 2) asyncRoot, sync appender and includeLocation="false" to print other logs
>
> Will it be difference if they print logs in two separate files?
>
>
> Thank you very much.
>
> Best regards,
>
> Dylan Su
>
>
>
>
>
> On Fri, Oct 16, 2015 at 7:21 PM, Strong Su <lo...@gmail.com> wrote:
>
>> Hello everyone,
>>
>> It takes me sometime to make sure that I have removed all log4j-1.2.16
>> and slf4j-log4j12.
>> It became better but not good enough.
>> Since sync log4j2 has already performed much better than log4j1, we
>> decided to use sync log4j2 first.
>> And I will start a fresh test over async log4j2 from beginning to
>> checkout where the problem is.
>>
>> I will update this thread or link this problem to a new thread when the
>> performance becomes normal.
>>
>> Thank you very much for the advices during these days.
>>
>> Best regards,
>> Dylan Su
>>
>> On Wed, Oct 14, 2015 at 4:58 PM, Strong Su <lo...@gmail.com> wrote:
>>
>>>
>>> ---------- Forwarded message ----------
>>> From: Gary Gregory <ga...@gmail.com>
>>> Date: Tue, Oct 13, 2015 at 9:58 PM
>>> Subject: Re: Bizarre performance in log4j2
>>> To: Log4J Users List <lo...@logging.apache.org>
>>>
>>>
>>> You can check with:
>>>
>>> mvn dependency:tree
>>>
>>> Gary
>>>
>>> On Tue, Oct 13, 2015 at 1:24 AM, Mikael Ståldal <
>>> mikael.staldal@magine.com>
>>> wrote:
>>>
>>> > ...and make sure that no 3rd party dependencies brings them in.
>>> >
>>> > On Tue, Oct 13, 2015 at 8:22 AM, Remko Popma <re...@gmail.com>
>>> > wrote:
>>> >
>>> > > Please remove log4j-1.2.16 and replace it with log4j-1.2-api version
>>> 2.3.
>>> > >
>>> > > Also remove slf4j-log4j12 and add log4j-slf4j-impl version 2.3.
>>> > >
>>> > > Sent from my iPhone
>>> > >
>>> > > > On 2015/10/13, at 14:39, Strong Su <lo...@gmail.com> wrote:
>>> > > >
>>> > > > Here is my pom.xml for logging:
>>> > > >
>>> > > > <dependency>
>>> > > >    <groupId>log4j</groupId>
>>> > > >    <artifactId>log4j</artifactId>
>>> > > >    <version>1.2.16</version>
>>> > > > </dependency>
>>> > > > <dependency>
>>> > > >    <groupId>org.slf4j</groupId>
>>> > > >    <artifactId>slf4j-log4j12</artifactId>
>>> > > >    <version>1.5.11</version>
>>> > > > </dependency>
>>> > > > <dependency>
>>> > > >    <groupId>org.slf4j</groupId>
>>> > > >    <artifactId>slf4j-api</artifactId>
>>> > > >    <version>1.5.11</version>
>>> > > > </dependency>
>>> > > > <dependency>
>>> > > >    <groupId>org.apache.logging.log4j</groupId>
>>> > > >    <artifactId>log4j-api</artifactId>
>>> > > >    <version>2.3</version>
>>> > > > </dependency>
>>> > > > <dependency>
>>> > > >    <groupId>org.apache.logging.log4j</groupId>
>>> > > >    <artifactId>log4j-core</artifactId>
>>> > > >    <version>2.3</version>
>>> > > > </dependency>
>>> > > > <dependency>
>>> > > >    <groupId>org.apache.logging.log4j</groupId>
>>> > > >    <artifactId>log4j-web</artifactId>
>>> > > >    <version>2.3</version>
>>> > > > </dependency>
>>> > > > <dependency>
>>> > > >    <groupId>com.lmax</groupId>
>>> > > >    <artifactId>disruptor</artifactId>
>>> > > >    <version>3.2.0</version>
>>> > > > </dependency>
>>> > > >
>>> > > >
>>> > > >> On Tue, Oct 13, 2015 at 12:22 PM, Remko Popma <
>>> remko.popma@gmail.com>
>>> > > wrote:
>>> > > >>
>>> > > >> For log4j1, are you using the log4j-1.2-api-2.x.jar? And
>>> similarly the
>>> > > >> log4j-slf4j-impl-2.x.jar for SLF4J? (Just checking...)
>>> > > >>
>>> > > >> Sent from my iPhone
>>> > > >>
>>> > > >>> On 2015/10/13, at 11:43, Gary Gregory <ga...@gmail.com>
>>> > wrote:
>>> > > >>>
>>> > > >>> Can you use 2.4?
>>> > > >>>
>>> > > >>> Gary
>>> > > >>>
>>> > > >>>> On Mon, Oct 12, 2015 at 6:56 PM, Strong Su <lovelosew@gmail.com
>>> >
>>> > > wrote:
>>> > > >>>>
>>> > > >>>> I'm using Log4j 2.3 and Disruptor 3.2.
>>> > > >>>> Because of third party package like spring, I have to use Log4j
>>> 1.2
>>> > > and
>>> > > >>>> slf4j 1.5 too.
>>> > > >>>>
>>> > > >>>>
>>> > > >>>> On Tue, Oct 13, 2015 at 7:15 AM, Remko Popma <
>>> remko.popma@gmail.com
>>> > >
>>> > > >>>> wrote:
>>> > > >>>>
>>> > > >>>>> Output looks ok.
>>> > > >>>>> Sleep was the default wait strategy but has been changed to
>>> Block a
>>> > > >> long
>>> > > >>>>> time ago. Looks like the docs are out of date. Thanks for
>>> drawing
>>> > my
>>> > > >>>>> attention to this.
>>> > > >>>>>
>>> > > >>>>> I don't understand why changing the includeLocation does not
>>> make a
>>> > > >>>>> difference in performance. You should see a large improvement.
>>> > > >>>>> Which Log4j version are you using?
>>> > > >>>>>
>>> > > >>>>>
>>> > > >>>>>
>>> > > >>>>>> On Mon, Oct 12, 2015 at 12:58 PM, Strong Su <
>>> lovelosew@gmail.com>
>>> > > >> wrote:
>>> > > >>>>>>
>>> > > >>>>>> Here is my console debug with status="trace".
>>> > > >>>>>> I found that log4j2 didn't get SleepWaitingStrategy by default
>>> > and I
>>> > > >>>>> didn't
>>> > > >>>>>> find includeLocation in console.
>>> > > >>>>>>
>>> > > >>>>>>
>>> > > >>>>>> 2015-10-12 18:55:25,424 DEBUG Starting
>>> > > LoggerContext[name=2090228673]
>>> > > >>>>> from
>>> > > >>>>>> configuration at jndi:/localhost/WEB-INF/log4j2.xml
>>> > > >>>>>> 2015-10-12 18:55:25,425 DEBUG Starting
>>> > > LoggerContext[name=2090228673,
>>> > > >>>>>> org.apache.logging.log4j.core.LoggerContext@4347ede7] with
>>> > > >>>> configuration
>>> > > >>>>>>
>>> XmlConfiguration[location=jndi:/localhost/WEB-INF/log4j2.xml]...
>>> > > >>>>>> 2015-10-12 18:55:25,427 DEBUG Shutdown hook enabled.
>>> Registering a
>>> > > new
>>> > > >>>>> one.
>>> > > >>>>>> 2015-10-12 18:55:25,430 DEBUG Starting configuration
>>> > > >>>>>> XmlConfiguration[location=jndi:/localhost/WEB-INF/log4j2.xml]
>>> > > >>>>>> 2015-10-12 18:55:25,432 DEBUG PluginManager 'Core' found 70
>>> > plugins
>>> > > >>>>>> 2015-10-12 18:55:25,433 DEBUG PluginManager 'Level' found 0
>>> > plugins
>>> > > >>>>>> 2015-10-12 18:55:25,438 DEBUG PluginManager 'Lookup' found 11
>>> > > plugins
>>> > > >>>>>> 2015-10-12 18:55:25,441 DEBUG Building Plugin[name=layout,
>>> > > >>>>>> class=org.apache.logging.log4j.core.layout.PatternLayout].
>>> > Searching
>>> > > >>>> for
>>> > > >>>>>> builder factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,445 DEBUG Found builder factory method
>>> > > >>>> [newBuilder]:
>>> > > >>>>>> public static
>>> > > >>>> org.apache.logging.log4j.core.layout.PatternLayout$Builder
>>> > > >>>>>>
>>> org.apache.logging.log4j.core.layout.PatternLayout.newBuilder().
>>> > > >>>>>> 2015-10-12 18:55:25,458 DEBUG TypeConverterRegistry
>>> initializing.
>>> > > >>>>>> 2015-10-12 18:55:25,458 DEBUG PluginManager 'TypeConverter'
>>> found
>>> > 21
>>> > > >>>>>> plugins
>>> > > >>>>>> 2015-10-12 18:55:25,480 DEBUG Calling build() on class class
>>> > > >>>>>> org.apache.logging.log4j.core.layout.PatternLayout$Builder for
>>> > > element
>>> > > >>>>>> PatternLayout with params(name="%d %-5p [%c{2}] %m%n",
>>> > > >>>>>> Configuration(jndi:/localhost/WEB-INF/log4j2.xml), null,
>>> > > name="null",
>>> > > >>>>>> name="null", name="null", name="null", name="null")
>>> > > >>>>>> 2015-10-12 18:55:25,481 DEBUG PluginManager 'Converter' found
>>> 33
>>> > > >>>> plugins
>>> > > >>>>>> 2015-10-12 18:55:25,482 DEBUG Built Plugin[name=layout] OK
>>> from
>>> > > >> builder
>>> > > >>>>>> factory method.
>>> > > >>>>>> 2015-10-12 18:55:25,483 DEBUG Building Plugin[name=appender,
>>> > > >>>>>> class=org.apache.logging.log4j.core.appender.FileAppender].
>>> > > Searching
>>> > > >>>> for
>>> > > >>>>>> builder factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,485 DEBUG No builder factory method found
>>> in
>>> > > class
>>> > > >>>>>> org.apache.logging.log4j.core.appender.FileAppender. Going to
>>> try
>>> > > >>>>> finding a
>>> > > >>>>>> factory method instead.
>>> > > >>>>>> 2015-10-12 18:55:25,486 DEBUG Still building
>>> Plugin[name=appender,
>>> > > >>>>>> class=org.apache.logging.log4j.core.appender.FileAppender].
>>> > > Searching
>>> > > >>>> for
>>> > > >>>>>> factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,486 DEBUG Found factory method
>>> > [createAppender]:
>>> > > >>>>> public
>>> > > >>>>>> static org.apache.logging.log4j.core.appender.FileAppender
>>> > > >>
>>> > >
>>> >
>>> org.apache.logging.log4j.core.appender.FileAppender.createAppender(java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,org.apache.logging.log4j.core.Layout,org.apache.logging.log4j.core.Filter,java.lang.String,java.lang.String,org.apache.logging.log4j.core.config.Configuration).
>>> > > >>>>>> 2015-10-12 18:55:25,500 DEBUG Calling createAppender on class
>>> > > >>>>>> org.apache.logging.log4j.core.appender.FileAppender for
>>> element
>>> > File
>>> > > >>>> with
>>> > > >>>>>> params(name="/data/applogs/data-proxy/logs/app.log",
>>> name="false",
>>> > > >>>>>> name="null", name="File", name="false", name="null",
>>> name="null",
>>> > > >>>>>> name="null", PatternLayout(%d %-5p [%c{2}] %m%n), null,
>>> > name="null",
>>> > > >>>>>> name="null",
>>> Configuration(jndi:/localhost/WEB-INF/log4j2.xml))
>>> > > >>>>>> 2015-10-12 18:55:25,504 DEBUG Starting FileManager
>>> > > >>>>>> /data/applogs/data-proxy/logs/app.log
>>> > > >>>>>> 2015-10-12 18:55:25,505 DEBUG Built Plugin[name=appender] OK
>>> from
>>> > > >>>> factory
>>> > > >>>>>> method.
>>> > > >>>>>> 2015-10-12 18:55:25,505 DEBUG Building Plugin[name=layout,
>>> > > >>>>>> class=org.apache.logging.log4j.core.layout.PatternLayout].
>>> > Searching
>>> > > >>>> for
>>> > > >>>>>> builder factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,505 DEBUG Found builder factory method
>>> > > >>>> [newBuilder]:
>>> > > >>>>>> public static
>>> > > >>>> org.apache.logging.log4j.core.layout.PatternLayout$Builder
>>> > > >>>>>>
>>> org.apache.logging.log4j.core.layout.PatternLayout.newBuilder().
>>> > > >>>>>> 2015-10-12 18:55:25,507 DEBUG Calling build() on class class
>>> > > >>>>>> org.apache.logging.log4j.core.layout.PatternLayout$Builder for
>>> > > element
>>> > > >>>>>> PatternLayout with params(name="%d %-5p [%c{2}] %m%n",
>>> > > >>>>>> Configuration(jndi:/localhost/WEB-INF/log4j2.xml), null,
>>> > > name="null",
>>> > > >>>>>> name="null", name="null", name="null", name="null")
>>> > > >>>>>> 2015-10-12 18:55:25,508 DEBUG Built Plugin[name=layout] OK
>>> from
>>> > > >> builder
>>> > > >>>>>> factory method.
>>> > > >>>>>> 2015-10-12 18:55:25,508 DEBUG Building Plugin[name=appender,
>>> > > >>>>>> class=org.apache.logging.log4j.core.appender.ConsoleAppender].
>>> > > >>>> Searching
>>> > > >>>>>> for builder factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,510 DEBUG PluginManager 'Converter' found
>>> 33
>>> > > >>>> plugins
>>> > > >>>>>> 2015-10-12 18:55:25,512 DEBUG Found builder factory method
>>> > > >>>> [newBuilder]:
>>> > > >>>>>> public static
>>> > > >>>>>> org.apache.logging.log4j.core.appender.ConsoleAppender$Builder
>>> > > >>>>>>
>>> > org.apache.logging.log4j.core.appender.ConsoleAppender.newBuilder().
>>> > > >>>>>> 2015-10-12 18:55:25,519 DEBUG No PluginVisitorStrategy found
>>> on
>>> > > >>>>> annotation
>>> > > >>>>>> [interface
>>> > > >>
>>> > >
>>> >
>>> org.apache.logging.log4j.core.config.plugins.validation.constraints.Required].
>>> > > >>>>>> Ignoring.
>>> > > >>>>>> 2015-10-12 18:55:25,520 DEBUG Encountered type
>>> > > >>>>>> [org.apache.logging.log4j.core.layout.PatternLayout] which can
>>> > only
>>> > > be
>>> > > >>>>>> checked for null.
>>> > > >>>>>> 2015-10-12 18:55:25,522 DEBUG No PluginVisitorStrategy found
>>> on
>>> > > >>>>> annotation
>>> > > >>>>>> [interface
>>> > > >>
>>> > >
>>> >
>>> org.apache.logging.log4j.core.config.plugins.validation.constraints.Required].
>>> > > >>>>>> Ignoring.
>>> > > >>>>>> 2015-10-12 18:55:25,523 DEBUG Encountered type
>>> > > >>>>>>
>>> [org.apache.logging.log4j.core.appender.ConsoleAppender$Target]
>>> > > which
>>> > > >>>> can
>>> > > >>>>>> only be checked for null.
>>> > > >>>>>> 2015-10-12 18:55:25,524 DEBUG No PluginVisitorStrategy found
>>> on
>>> > > >>>>> annotation
>>> > > >>>>>> [interface
>>> > > >>
>>> > >
>>> >
>>> org.apache.logging.log4j.core.config.plugins.validation.constraints.Required].
>>> > > >>>>>> Ignoring.
>>> > > >>>>>> 2015-10-12 18:55:25,525 DEBUG Calling build() on class class
>>> > > >>>>>>
>>> org.apache.logging.log4j.core.appender.ConsoleAppender$Builder for
>>> > > >>>>> element
>>> > > >>>>>> Console with params(PatternLayout(%d %-5p [%c{2}] %m%n), null,
>>> > > >>>>>> name="SYSTEM_OUT", name="STDOUT", name="null", name="null")
>>> > > >>>>>> 2015-10-12 18:55:25,526 DEBUG Built Plugin[name=appender] OK
>>> from
>>> > > >>>> builder
>>> > > >>>>>> factory method.
>>> > > >>>>>> 2015-10-12 18:55:25,526 DEBUG Building Plugin[name=appenders,
>>> > > >>>>>> class=org.apache.logging.log4j.core.config.AppendersPlugin].
>>> > > Searching
>>> > > >>>>> for
>>> > > >>>>>> builder factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,527 DEBUG No builder factory method found
>>> in
>>> > > class
>>> > > >>>>>> org.apache.logging.log4j.core.config.AppendersPlugin. Going
>>> to try
>>> > > >>>>> finding
>>> > > >>>>>> a factory method instead.
>>> > > >>>>>> 2015-10-12 18:55:25,527 DEBUG Still building
>>> > Plugin[name=appenders,
>>> > > >>>>>> class=org.apache.logging.log4j.core.config.AppendersPlugin].
>>> > > Searching
>>> > > >>>>> for
>>> > > >>>>>> factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,528 DEBUG Found factory method
>>> > > [createAppenders]:
>>> > > >>>>>> public static java.util.concurrent.ConcurrentMap
>>> > > >>
>>> > >
>>> >
>>> org.apache.logging.log4j.core.config.AppendersPlugin.createAppenders(org.apache.logging.log4j.core.Appender[]).
>>> > > >>>>>> 2015-10-12 18:55:25,530 DEBUG Calling createAppenders on class
>>> > > >>>>>> org.apache.logging.log4j.core.config.AppendersPlugin for
>>> element
>>> > > >>>>> Appenders
>>> > > >>>>>> with params(={File, STDOUT})
>>> > > >>>>>> 2015-10-12 18:55:25,532 DEBUG Built Plugin[name=appenders] OK
>>> from
>>> > > >>>>> factory
>>> > > >>>>>> method.
>>> > > >>>>>> 2015-10-12 18:55:25,532 DEBUG Building
>>> Plugin[name=AppenderRef,
>>> > > >>>>>> class=org.apache.logging.log4j.core.config.AppenderRef].
>>> Searching
>>> > > for
>>> > > >>>>>> builder factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,534 DEBUG No builder factory method found
>>> in
>>> > > class
>>> > > >>>>>> org.apache.logging.log4j.core.config.AppenderRef. Going to try
>>> > > finding
>>> > > >>>> a
>>> > > >>>>>> factory method instead.
>>> > > >>>>>> 2015-10-12 18:55:25,535 DEBUG Still building
>>> > > Plugin[name=AppenderRef,
>>> > > >>>>>> class=org.apache.logging.log4j.core.config.AppenderRef].
>>> Searching
>>> > > for
>>> > > >>>>>> factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,536 DEBUG Found factory method
>>> > > >> [createAppenderRef]:
>>> > > >>>>>> public static org.apache.logging.log4j.core.config.AppenderRef
>>> > > >>
>>> > >
>>> >
>>> org.apache.logging.log4j.core.config.AppenderRef.createAppenderRef(java.lang.String,org.apache.logging.log4j.Level,org.apache.logging.log4j.core.Filter).
>>> > > >>>>>> 2015-10-12 18:55:25,538 DEBUG Calling createAppenderRef on
>>> class
>>> > > >>>>>> org.apache.logging.log4j.core.config.AppenderRef for element
>>> > > >>>> AppenderRef
>>> > > >>>>>> with params(name="File", name="null", null)
>>> > > >>>>>> 2015-10-12 18:55:25,539 DEBUG Built Plugin[name=AppenderRef]
>>> OK
>>> > from
>>> > > >>>>>> factory method.
>>> > > >>>>>> 2015-10-12 18:55:25,540 DEBUG Building
>>> Plugin[name=AppenderRef,
>>> > > >>>>>> class=org.apache.logging.log4j.core.config.AppenderRef].
>>> Searching
>>> > > for
>>> > > >>>>>> builder factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,540 DEBUG No builder factory method found
>>> in
>>> > > class
>>> > > >>>>>> org.apache.logging.log4j.core.config.AppenderRef. Going to try
>>> > > finding
>>> > > >>>> a
>>> > > >>>>>> factory method instead.
>>> > > >>>>>> 2015-10-12 18:55:25,541 DEBUG Still building
>>> > > Plugin[name=AppenderRef,
>>> > > >>>>>> class=org.apache.logging.log4j.core.config.AppenderRef].
>>> Searching
>>> > > for
>>> > > >>>>>> factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,543 DEBUG Found factory method
>>> > > >> [createAppenderRef]:
>>> > > >>>>>> public static org.apache.logging.log4j.core.config.AppenderRef
>>> > > >>
>>> > >
>>> >
>>> org.apache.logging.log4j.core.config.AppenderRef.createAppenderRef(java.lang.String,org.apache.logging.log4j.Level,org.apache.logging.log4j.core.Filter).
>>> > > >>>>>> 2015-10-12 18:55:25,546 DEBUG Calling createAppenderRef on
>>> class
>>> > > >>>>>> org.apache.logging.log4j.core.config.AppenderRef for element
>>> > > >>>> AppenderRef
>>> > > >>>>>> with params(name="STDOUT", name="null", null)
>>> > > >>>>>> 2015-10-12 18:55:25,547 DEBUG Built Plugin[name=AppenderRef]
>>> OK
>>> > from
>>> > > >>>>>> factory method.
>>> > > >>>>>> 2015-10-12 18:55:25,548 DEBUG Building Plugin[name=asyncRoot,
>>> > > >>>>
>>> > >
>>> class=org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger].
>>> > > >>>>>> Searching for builder factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,551 DEBUG No builder factory method found
>>> in
>>> > > class
>>> > > >>>>>>
>>> org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger.
>>> > > >> Going
>>> > > >>>>> to
>>> > > >>>>>> try finding a factory method instead.
>>> > > >>>>>> 2015-10-12 18:55:25,552 DEBUG Still building
>>> > Plugin[name=asyncRoot,
>>> > > >>>>
>>> > >
>>> class=org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger].
>>> > > >>>>>> Searching for factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,554 DEBUG Found factory method
>>> [createLogger]:
>>> > > >>>> public
>>> > > >>>>>> static org.apache.logging.log4j.core.config.LoggerConfig
>>> > > >>
>>> > >
>>> >
>>> org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger.createLogger(java.lang.String,java.lang.String,java.lang.String,org.apache.logging.log4j.core.config.AppenderRef[],org.apache.logging.log4j.core.config.Property[],org.apache.logging.log4j.core.config.Configuration,org.apache.logging.log4j.core.Filter).
>>> > > >>>>>> 2015-10-12 18:55:25,559 DEBUG Calling createLogger on class
>>> > > >>>>>>
>>> org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger
>>> > for
>>> > > >>>>>> element asyncRoot with params(name="null", name="info",
>>> > > name="false",
>>> > > >>>>>> ={File, STDOUT}, ={},
>>> > > >>>> Configuration(jndi:/localhost/WEB-INF/log4j2.xml),
>>> > > >>>>>> null)
>>> > > >>>>>> 2015-10-12 18:55:25,560 DEBUG Built Plugin[name=asyncRoot] OK
>>> from
>>> > > >>>>> factory
>>> > > >>>>>> method.
>>> > > >>>>>> 2015-10-12 18:55:25,561 DEBUG Building Plugin[name=loggers,
>>> > > >>>>>> class=org.apache.logging.log4j.core.config.LoggersPlugin].
>>> > Searching
>>> > > >>>> for
>>> > > >>>>>> builder factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,564 DEBUG No builder factory method found
>>> in
>>> > > class
>>> > > >>>>>> org.apache.logging.log4j.core.config.LoggersPlugin. Going to
>>> try
>>> > > >>>> finding
>>> > > >>>>> a
>>> > > >>>>>> factory method instead.
>>> > > >>>>>> 2015-10-12 18:55:25,565 DEBUG Still building
>>> Plugin[name=loggers,
>>> > > >>>>>> class=org.apache.logging.log4j.core.config.LoggersPlugin].
>>> > Searching
>>> > > >>>> for
>>> > > >>>>>> factory method...
>>> > > >>>>>> 2015-10-12 18:55:25,565 DEBUG Found factory method
>>> > [createLoggers]:
>>> > > >>>>> public
>>> > > >>>>>> static org.apache.logging.log4j.core.config.Loggers
>>> > > >>
>>> > >
>>> >
>>> org.apache.logging.log4j.core.config.LoggersPlugin.createLoggers(org.apache.logging.log4j.core.config.LoggerConfig[]).
>>> > > >>>>>> 2015-10-12 18:55:25,566 DEBUG Calling createLoggers on class
>>> > > >>>>>> org.apache.logging.log4j.core.config.LoggersPlugin for element
>>> > > Loggers
>>> > > >>>>> with
>>> > > >>>>>> params(={root})
>>> > > >>>>>> 2015-10-12 18:55:25,566 DEBUG Built Plugin[name=loggers] OK
>>> from
>>> > > >>>> factory
>>> > > >>>>>> method.
>>> > > >>>>>> 2015-10-12 18:55:25,567 TRACE AsyncLoggerConfig[root]
>>> starting...
>>> > > >>>>>> 2015-10-12 18:55:25,574 TRACE AsyncLoggerConfigHelper
>>> creating new
>>> > > >>>>>> disruptor. Ref count is 1.
>>> > > >>>>>> 2015-10-12 18:55:25,574 DEBUG property
>>> > > >>>>> AsyncLoggerConfig.WaitStrategy=null
>>> > > >>>>>> 2015-10-12 18:55:25,575 DEBUG disruptor event handler uses
>>> > > >>>>>> BlockingWaitStrategy
>>> > > >>>>>> 2015-10-12 18:55:25,625 DEBUG Starting AsyncLoggerConfig
>>> disruptor
>>> > > >> with
>>> > > >>>>>> ringbuffer size=262144, waitStrategy=BlockingWaitStrategy,
>>> > > >>>>>> exceptionHandler=null...
>>> > > >>>>>> 2015-10-12 18:55:25,627 DEBUG Started configuration
>>> > > >>>>>> XmlConfiguration[location=jndi:/localhost/WEB-INF/log4j2.xml]
>>> OK.
>>> > > >>>>>> 2015-10-12 18:55:25,627 TRACE Stopping
>>> > > >>>>>>
>>> > org.apache.logging.log4j.core.config.DefaultConfiguration@75c1ada7.
>>> > > ..
>>> > > >>>>>> 2015-10-12 18:55:25,628 TRACE AbstractConfiguration stopped 0
>>> > > >>>>>> AsyncLoggerConfigs.
>>> > > >>>>>> 2015-10-12 18:55:25,628 TRACE AbstractConfiguration stopped 0
>>> > > >>>>>> AsyncAppenders.
>>> > > >>>>>> 2015-10-12 18:55:25,628 TRACE AbstractConfiguration stopped 1
>>> > > >>>> Appenders.
>>> > > >>>>>> 2015-10-12 18:55:25,628 TRACE AbstractConfiguration stopped 0
>>> > > Loggers.
>>> > > >>>>>> 2015-10-12 18:55:25,629 DEBUG Stopped
>>> > > >>>>>>
>>> org.apache.logging.log4j.core.config.DefaultConfiguration@75c1ada7
>>> > > OK
>>> > > >>>>>> 2015-10-12 18:55:25,634 DEBUG Registering MBean
>>> > > >>>>>> org.apache.logging.log4j2:type=2090228673
>>> > > >>>>>> 2015-10-12 18:55:25,642 DEBUG Registering MBean
>>> > > >>>>>>
>>> org.apache.logging.log4j2:type=2090228673,component=StatusLogger
>>> > > >>>>>> 2015-10-12 18:55:25,647 DEBUG Registering MBean
>>> > > >>>>>>
>>> > org.apache.logging.log4j2:type=2090228673,component=ContextSelector
>>> > > >>>>>> 2015-10-12 18:55:25,649 DEBUG Registering MBean
>>> > > >>>>>>
>>> org.apache.logging.log4j2:type=2090228673,component=Loggers,name=
>>> > > >>>>>> 2015-10-12 18:55:25,653 DEBUG Registering MBean
>>> > > >>
>>> > >
>>> >
>>> org.apache.logging.log4j2:type=2090228673,component=Loggers,name=,subtype=RingBuffer
>>> > > >>>>>> 2015-10-12 18:55:25,657 DEBUG Registering MBean
>>> > > >>
>>> > >
>>> org.apache.logging.log4j2:type=2090228673,component=Appenders,name=STDOUT
>>> > > >>>>>> 2015-10-12 18:55:25,659 DEBUG Registering MBean
>>> > > >>
>>> > org.apache.logging.log4j2:type=2090228673,component=Appenders,name=File
>>> > > >>>>>> 2015-10-12 18:55:25,660 DEBUG LoggerContext[name=2090228673,
>>> > > >>>>>> org.apache.logging.log4j.core.LoggerContext@4347ede7]
>>> started OK
>>> > > with
>>> > > >>>>>> configuration
>>> > > >>>>>> XmlConfiguration[location=jndi:/localhost/WEB-INF/log4j2.xml].
>>> > > >>>>>> 2015-10-12 18:55:26,198 DEBUG Starting RollingFileManager
>>> > > >>>>>> /data/applogs/pigeon/pigeon.data-proxy.log
>>> > > >>>>>> 2015-10-12 18:55:26,200 DEBUG PluginManager 'FileConverter'
>>> found
>>> > 2
>>> > > >>>>> plugins
>>> > > >>>>>> 2015-10-12 18:55:26,203 TRACE PatternProcessor.getNextTime
>>> > returning
>>> > > >>>>>> 2015/10/13-00:00:00.000, nextFileTime=2015/10/12-00:00:00.000,
>>> > > >>>>>> prevFileTime=1970/01/01-08:00:00.000,
>>> > > current=2015/10/12-18:55:26.202,
>>> > > >>>>>> freq=DAILY
>>> > > >>>>>> 2015-10-12 18:55:26,204 TRACE PatternProcessor.getNextTime
>>> > returning
>>> > > >>>>>> 2015/10/13-00:00:00.000, nextFileTime=2015/10/12-00:00:00.000,
>>> > > >>>>>> prevFileTime=2015/10/12-00:00:00.000,
>>> > > current=2015/10/12-18:55:26.203,
>>> > > >>>>>> freq=DAILY
>>> > > >>>>>> 2015-10-12 18:55:26,204 DEBUG Starting OutputStreamManager
>>> > > SYSTEM_ERR
>>> > > >>>>>> 2015-10-12 18:55:26,207 DEBUG Starting RollingFileManager
>>> > > >>>>>> /data/applogs/pigeon/pigeon.data-proxy.access.log
>>> > > >>>>>> 2015-10-12 18:55:26,207 DEBUG PluginManager 'FileConverter'
>>> found
>>> > 2
>>> > > >>>>> plugins
>>> > > >>>>>> 2015-10-12 18:55:26,208 TRACE PatternProcessor.getNextTime
>>> > returning
>>> > > >>>>>> 2015/09/30-00:00:00.000, nextFileTime=2015/09/29-00:00:00.000,
>>> > > >>>>>> prevFileTime=1970/01/01-08:00:00.000,
>>> > > current=2015/10/12-18:55:26.208,
>>> > > >>>>>> freq=DAILY
>>> > > >>>>>> 2015-10-12 18:55:26,209 TRACE PatternProcessor.getNextTime
>>> > returning
>>> > > >>>>>> 2015/09/30-00:00:00.000, nextFileTime=2015/09/29-00:00:00.000,
>>> > > >>>>>> prevFileTime=2015/09/29-00:00:00.000,
>>> > > current=2015/10/12-18:55:26.209,
>>> > > >>>>>> freq=DAILY
>>> > > >>>>>> 2015-10-12 18:55:26,239 DEBUG Using default SystemClock for
>>> > > timestamps
>>> > > >>>
>>> > > >>>
>>> > > >>>
>>> > > >>> --
>>> > > >>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>> > > >>> Java Persistence with Hibernate, Second Edition
>>> > > >>> <http://www.manning.com/bauer3/>
>>> > > >>> JUnit in Action, Second Edition <
>>> http://www.manning.com/tahchiev/>
>>> > > >>> Spring Batch in Action <http://www.manning.com/templier/>
>>> > > >>> Blog: http://garygregory.wordpress.com
>>> > > >>> Home: http://garygregory.com/
>>> > > >>> Tweet! http://twitter.com/GaryGregory
>>> > > >>
>>> > > >>
>>> ---------------------------------------------------------------------
>>> > > >> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
>>> > > >> For additional commands, e-mail:
>>> log4j-user-help@logging.apache.org
>>> > > >>
>>> > > >>
>>> > >
>>> > > ---------------------------------------------------------------------
>>> > > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
>>> > > For additional commands, e-mail: log4j-user-help@logging.apache.org
>>> > >
>>> > >
>>> >
>>> >
>>> > --
>>> > [image: MagineTV]
>>> >
>>> > *Mikael Ståldal*
>>> > Senior software developer
>>> >
>>> > *Magine TV*
>>> > mikael.staldal@magine.com
>>> > Regeringsgatan 25  | 111 53 Stockholm, Sweden  |   www.magine.com
>>> >
>>> > Privileged and/or Confidential Information may be contained in this
>>> > message. If you are not the addressee indicated in this message
>>> > (or responsible for delivery of the message to such a person), you may
>>> not
>>> > copy or deliver this message to anyone. In such case,
>>> > you should destroy this message and kindly notify the sender by reply
>>> > email.
>>> >
>>>
>>>
>>>
>>> --
>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>> Java Persistence with Hibernate, Second Edition
>>> <http://www.manning.com/bauer3/>
>>> JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
>>> Spring Batch in Action <http://www.manning.com/templier/>
>>> Blog: http://garygregory.wordpress.com
>>> Home: http://garygregory.com/
>>> Tweet! http://twitter.com/GaryGregory
>>>
>>>
>>
>

Re: Bizarre performance in log4j2

Posted by Remko Popma <re...@gmail.com>.
Please review this issue to see if it would address your concern about appenders not keeping up with the application logging rate:
https://issues.apache.org/jira/browse/LOG4J2-1080

Remko 

Sent from my iPhone

> On 2015/12/10, at 18:09, Strong Su <lo...@gmail.com> wrote:
> 
> Hello everyone,
> We re-test log4j2's performance in our system from the very beginning. In
> our case, there two factors which will decrease the performance heavily.
> 1. %c or %class
>    As Remko said, the information of location(you can see the log4j2.xml
> above)  will hurt async logger badly. And when I remove it, the performance
> returns normal.
> 2. ringBuffer
>    My mentor, Erik Fang(fmerik@gmail.com), changed the source code of
> AsyncLogger and add a little counter to measure the status of ringBuffer.
> When a request came, the counter will plus 1 if the ringBuffer is full for
> that moment. And calculate the ratio(counter/requestsNum), call it
> fullRatio, when all the requests are done.
>    It turns out that when fullRatio becomes high, the performance(QPS)
> will drop very quickly. I test it in our system and it's confirmed.
>    I print a log whenever a request comes in my origin test and I change
> the log's size like 10bytes, 100bytes and so on. The performance of
> sync_log4j2 and async_log4j2 seemed normal(around 30k) and it's almost the
> same as the performance when I don't print logs, which is great, and
> fullRatio of async_log4j2 is lower than 1%. But as I increase the size of
> one log(more than 1Kb) and number of threads, fullRatio can be up to more
> than 8% and QPS of async_log4j2 drops to 19k and QPS of sync_log4j2 is
> still 26k. As a result, we think factors, like extremely long logs and
> numerous threads, which may make the speed of disruptor's consumer(appender
> in log4j2) lower than disruptor's producer(logger in log4j2) can also
> influence the performance in async_log4j2.
> 
> PS:
> During the Test.
> I insert a log in a http request function on server side. And I start
> requests continually on client side through hundreds of threads.
> I measure the performance through QPS because server has to print a log
> whenever it receive a request. The time delayed by logging will influence
> QPS heavily.
> I continually increasing the number of client until QPS reaches the limit.
> The highest QPS appears when the number of client is about 400 but QPS will
> drop and fullRatio will increase after that.
> 
> Thank Erik and Remko very much.
> 
> Best Regards,
> Dylan Su
> 
> 
> 
> 
> 
> 
>> On Tue, Oct 20, 2015 at 3:38 PM, Strong Su <lo...@gmail.com> wrote:
>> 
>> Hello everyone,
>> I take a deep look at our project and found one of our third dependencies
>> was using log4j2. It is using APIs of log4j2 instead of configuration files
>> but it can recognise and use my log4j2.xml.
>> I wrote a simple example to illustrate how log4j2 be added in the third
>> dependency.
>> 
>> *Function_A:*
>> 
>> public void function_A(){
>> 
>>        LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
>> 
>>        Configuration config = ctx.getConfiguration();
>> 
>>        Layout layout = PatternLayout.createLayout(
>> 
>>                "%d{yyyy-MM-dd HH:mm:ss} [%t] %-5level %class{36} %L %M -
>> %msg%xEx%n", config, null, null, true, false, null, null);
>> 
>> 
>>        ConsoleAppender consoleAppender = ConsoleAppender.createAppender(
>> layout, null, "SYSTEM_OUT", "consoleAppender", "false", "false");
>> 
>>        AppenderRef consoleRef = AppenderRef.createAppenderRef(
>> "consoleAppender", Level.INFO, null);
>> 
>>        AppenderRef[] crefs = new AppenderRef[] { consoleRef };
>> 
>>        consoleAppender.start();
>> 
>>        config.addAppender(consoleAppender);
>> 
>> 
>> 
>>        AsyncAppender asyncAppender = AsyncAppender.createAppender(crefs,
>> null,
>> 
>>                true, 128, "asyncAppender", false, null, config, false);
>> 
>>        AppenderRef accessRef = AppenderRef.createAppenderRef(
>> "asyncAppender", Level.INFO, null);
>> 
>>        AppenderRef[] arefs = new AppenderRef[] { accessRef };
>> 
>>        asyncAppender.start();
>> 
>>        config.addAppender(asyncAppender);
>> 
>> 
>>        LoggerConfig loggerConfig = LoggerConfig.createLogger("false",
>> Level.INFO, "com.TestMain", "true", arefs, null, config, null);
>> 
>>        loggerConfig.addAppender(consoleAppender, Level.INFO, null);
>> 
>>        config.addLogger("com.TestMain", loggerConfig);
>> 
>>        Logger LOG = ctx.getLogger("com.TestMain");
>> 
>> }
>> 
>> *Log4j2.xml:*
>> 
>> <?xml version="1.0" encoding="UTF-8"?>
>> 
>> <Configuration status="warn">
>> 
>>    <Appenders>
>> 
>>        <Console name="Console" target="SYSTEM_OUT">
>> 
>>            <PatternLayout pattern="%d %-5p %logger{36}  %msg%n"/>
>> 
>>        </Console>
>> 
>>    </Appenders>
>> 
>>    <Loggers>
>> 
>>        <Root level="info">
>> 
>>            <AppenderRef ref="Console" />
>> 
>>        </Root>
>> 
>>    </Loggers>
>> 
>> </Configuration>
>> 
>> 
>> I will call the appender in function_A as appender_API, and call the
>> appender from log4j2.xml as appender_XML.
>> 
>> Through my tests to print log using logger, named LOG, from function_A. I
>> found these phenomenons:
>> 
>> 1) just use the function_A and log4j2.xml above
>> 
>>    logs will be printed by appender_API
>> 
>> 2) add <logger name="com.TestMain" level="info"><AppenderRef
>> ref="Console"/></logger> in tag <Loggers> of log4j2.xml
>> 
>>    logs will be printed by appender_XML twice although I have set
>> additivity="false" when I create logger in function_A
>> 
>> 3) add <logger name="com.TestMain" level="info"
>> additivity="false"><AppenderRef ref="Console"/></logger> in tag <Loggers>
>> of log4j2.xml
>> 
>>    logs will be printed by appender_XML once
>> 
>> 
>> How can I explain these? All I can think is that the configuration of
>> logger from log4j2.xml covers the configuration from function_A. But
>> I'm little confusion about the load sequence between different loggers.
>> 
>> 
>> Besides, the configuration of logger named "com.TestMain" has location
>> information and it sets includeLocation="true".
>> 
>> To test async logger in log4j2, I just change <root> to <asyncRoot>
>> comparing the <Loggers>'s configs of log4j2.xml from above and it turns out
>> a even worse performance in my early tests. Will the combination below
>> influence the performance if these two loggers print logs in the same file?
>> 
>> 1) sync logger, async appender and includeLocation="true" to print logs
>> from function_A
>> 
>> 2) asyncRoot, sync appender and includeLocation="false" to print other logs
>> 
>> Will it be difference if they print logs in two separate files?
>> 
>> 
>> Thank you very much.
>> 
>> Best regards,
>> 
>> Dylan Su
>> 
>> 
>> 
>> 
>> 
>>> On Fri, Oct 16, 2015 at 7:21 PM, Strong Su <lo...@gmail.com> wrote:
>>> 
>>> Hello everyone,
>>> 
>>> It takes me sometime to make sure that I have removed all log4j-1.2.16
>>> and slf4j-log4j12.
>>> It became better but not good enough.
>>> Since sync log4j2 has already performed much better than log4j1, we
>>> decided to use sync log4j2 first.
>>> And I will start a fresh test over async log4j2 from beginning to
>>> checkout where the problem is.
>>> 
>>> I will update this thread or link this problem to a new thread when the
>>> performance becomes normal.
>>> 
>>> Thank you very much for the advices during these days.
>>> 
>>> Best regards,
>>> Dylan Su
>>> 
>>>> On Wed, Oct 14, 2015 at 4:58 PM, Strong Su <lo...@gmail.com> wrote:
>>>> 
>>>> 
>>>> ---------- Forwarded message ----------
>>>> From: Gary Gregory <ga...@gmail.com>
>>>> Date: Tue, Oct 13, 2015 at 9:58 PM
>>>> Subject: Re: Bizarre performance in log4j2
>>>> To: Log4J Users List <lo...@logging.apache.org>
>>>> 
>>>> 
>>>> You can check with:
>>>> 
>>>> mvn dependency:tree
>>>> 
>>>> Gary
>>>> 
>>>> On Tue, Oct 13, 2015 at 1:24 AM, Mikael Ståldal <
>>>> mikael.staldal@magine.com>
>>>> wrote:
>>>> 
>>>>> ...and make sure that no 3rd party dependencies brings them in.
>>>>> 
>>>>> On Tue, Oct 13, 2015 at 8:22 AM, Remko Popma <re...@gmail.com>
>>>>> wrote:
>>>>> 
>>>>>> Please remove log4j-1.2.16 and replace it with log4j-1.2-api version
>>>> 2.3.
>>>>>> 
>>>>>> Also remove slf4j-log4j12 and add log4j-slf4j-impl version 2.3.
>>>>>> 
>>>>>> Sent from my iPhone
>>>>>> 
>>>>>>> On 2015/10/13, at 14:39, Strong Su <lo...@gmail.com> wrote:
>>>>>>> 
>>>>>>> Here is my pom.xml for logging:
>>>>>>> 
>>>>>>> <dependency>
>>>>>>>   <groupId>log4j</groupId>
>>>>>>>   <artifactId>log4j</artifactId>
>>>>>>>   <version>1.2.16</version>
>>>>>>> </dependency>
>>>>>>> <dependency>
>>>>>>>   <groupId>org.slf4j</groupId>
>>>>>>>   <artifactId>slf4j-log4j12</artifactId>
>>>>>>>   <version>1.5.11</version>
>>>>>>> </dependency>
>>>>>>> <dependency>
>>>>>>>   <groupId>org.slf4j</groupId>
>>>>>>>   <artifactId>slf4j-api</artifactId>
>>>>>>>   <version>1.5.11</version>
>>>>>>> </dependency>
>>>>>>> <dependency>
>>>>>>>   <groupId>org.apache.logging.log4j</groupId>
>>>>>>>   <artifactId>log4j-api</artifactId>
>>>>>>>   <version>2.3</version>
>>>>>>> </dependency>
>>>>>>> <dependency>
>>>>>>>   <groupId>org.apache.logging.log4j</groupId>
>>>>>>>   <artifactId>log4j-core</artifactId>
>>>>>>>   <version>2.3</version>
>>>>>>> </dependency>
>>>>>>> <dependency>
>>>>>>>   <groupId>org.apache.logging.log4j</groupId>
>>>>>>>   <artifactId>log4j-web</artifactId>
>>>>>>>   <version>2.3</version>
>>>>>>> </dependency>
>>>>>>> <dependency>
>>>>>>>   <groupId>com.lmax</groupId>
>>>>>>>   <artifactId>disruptor</artifactId>
>>>>>>>   <version>3.2.0</version>
>>>>>>> </dependency>
>>>>>>> 
>>>>>>> 
>>>>>>>> On Tue, Oct 13, 2015 at 12:22 PM, Remko Popma <
>>>> remko.popma@gmail.com>
>>>>>> wrote:
>>>>>>>> 
>>>>>>>> For log4j1, are you using the log4j-1.2-api-2.x.jar? And
>>>> similarly the
>>>>>>>> log4j-slf4j-impl-2.x.jar for SLF4J? (Just checking...)
>>>>>>>> 
>>>>>>>> Sent from my iPhone
>>>>>>>> 
>>>>>>>>> On 2015/10/13, at 11:43, Gary Gregory <ga...@gmail.com>
>>>>> wrote:
>>>>>>>>> 
>>>>>>>>> Can you use 2.4?
>>>>>>>>> 
>>>>>>>>> Gary
>>>>>>>>> 
>>>>>>>>>> On Mon, Oct 12, 2015 at 6:56 PM, Strong Su <lovelosew@gmail.com
>>>>> 
>>>>>> wrote:
>>>>>>>>>> 
>>>>>>>>>> I'm using Log4j 2.3 and Disruptor 3.2.
>>>>>>>>>> Because of third party package like spring, I have to use Log4j
>>>> 1.2
>>>>>> and
>>>>>>>>>> slf4j 1.5 too.
>>>>>>>>>> 
>>>>>>>>>> 
>>>>>>>>>> On Tue, Oct 13, 2015 at 7:15 AM, Remko Popma <
>>>> remko.popma@gmail.com
>>>>>> 
>>>>>>>>>> wrote:
>>>>>>>>>> 
>>>>>>>>>>> Output looks ok.
>>>>>>>>>>> Sleep was the default wait strategy but has been changed to
>>>> Block a
>>>>>>>> long
>>>>>>>>>>> time ago. Looks like the docs are out of date. Thanks for
>>>> drawing
>>>>> my
>>>>>>>>>>> attention to this.
>>>>>>>>>>> 
>>>>>>>>>>> I don't understand why changing the includeLocation does not
>>>> make a
>>>>>>>>>>> difference in performance. You should see a large improvement.
>>>>>>>>>>> Which Log4j version are you using?
>>>>>>>>>>> 
>>>>>>>>>>> 
>>>>>>>>>>> 
>>>>>>>>>>>> On Mon, Oct 12, 2015 at 12:58 PM, Strong Su <
>>>> lovelosew@gmail.com>
>>>>>>>> wrote:
>>>>>>>>>>>> 
>>>>>>>>>>>> Here is my console debug with status="trace".
>>>>>>>>>>>> I found that log4j2 didn't get SleepWaitingStrategy by default
>>>>> and I
>>>>>>>>>>> didn't
>>>>>>>>>>>> find includeLocation in console.
>>>>>>>>>>>> 
>>>>>>>>>>>> 
>>>>>>>>>>>> 2015-10-12 18:55:25,424 DEBUG Starting
>>>>>> LoggerContext[name=2090228673]
>>>>>>>>>>> from
>>>>>>>>>>>> configuration at jndi:/localhost/WEB-INF/log4j2.xml
>>>>>>>>>>>> 2015-10-12 18:55:25,425 DEBUG Starting
>>>>>> LoggerContext[name=2090228673,
>>>>>>>>>>>> org.apache.logging.log4j.core.LoggerContext@4347ede7] with
>>>>>>>>>> configuration
>>>> XmlConfiguration[location=jndi:/localhost/WEB-INF/log4j2.xml]...
>>>>>>>>>>>> 2015-10-12 18:55:25,427 DEBUG Shutdown hook enabled.
>>>> Registering a
>>>>>> new
>>>>>>>>>>> one.
>>>>>>>>>>>> 2015-10-12 18:55:25,430 DEBUG Starting configuration
>>>>>>>>>>>> XmlConfiguration[location=jndi:/localhost/WEB-INF/log4j2.xml]
>>>>>>>>>>>> 2015-10-12 18:55:25,432 DEBUG PluginManager 'Core' found 70
>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:25,433 DEBUG PluginManager 'Level' found 0
>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:25,438 DEBUG PluginManager 'Lookup' found 11
>>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:25,441 DEBUG Building Plugin[name=layout,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.layout.PatternLayout].
>>>>> Searching
>>>>>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,445 DEBUG Found builder factory method
>>>>>>>>>> [newBuilder]:
>>>>>>>>>>>> public static
>>>>>>>>>> org.apache.logging.log4j.core.layout.PatternLayout$Builder
>>>> org.apache.logging.log4j.core.layout.PatternLayout.newBuilder().
>>>>>>>>>>>> 2015-10-12 18:55:25,458 DEBUG TypeConverterRegistry
>>>> initializing.
>>>>>>>>>>>> 2015-10-12 18:55:25,458 DEBUG PluginManager 'TypeConverter'
>>>> found
>>>>> 21
>>>>>>>>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:25,480 DEBUG Calling build() on class class
>>>>>>>>>>>> org.apache.logging.log4j.core.layout.PatternLayout$Builder for
>>>>>> element
>>>>>>>>>>>> PatternLayout with params(name="%d %-5p [%c{2}] %m%n",
>>>>>>>>>>>> Configuration(jndi:/localhost/WEB-INF/log4j2.xml), null,
>>>>>> name="null",
>>>>>>>>>>>> name="null", name="null", name="null", name="null")
>>>>>>>>>>>> 2015-10-12 18:55:25,481 DEBUG PluginManager 'Converter' found
>>>> 33
>>>>>>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:25,482 DEBUG Built Plugin[name=layout] OK
>>>> from
>>>>>>>> builder
>>>>>>>>>>>> factory method.
>>>>>>>>>>>> 2015-10-12 18:55:25,483 DEBUG Building Plugin[name=appender,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.appender.FileAppender].
>>>>>> Searching
>>>>>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,485 DEBUG No builder factory method found
>>>> in
>>>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.appender.FileAppender. Going to
>>>> try
>>>>>>>>>>> finding a
>>>>>>>>>>>> factory method instead.
>>>>>>>>>>>> 2015-10-12 18:55:25,486 DEBUG Still building
>>>> Plugin[name=appender,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.appender.FileAppender].
>>>>>> Searching
>>>>>>>>>> for
>>>>>>>>>>>> factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,486 DEBUG Found factory method
>>>>> [createAppender]:
>>>>>>>>>>> public
>>>>>>>>>>>> static org.apache.logging.log4j.core.appender.FileAppender
>>>> org.apache.logging.log4j.core.appender.FileAppender.createAppender(java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,org.apache.logging.log4j.core.Layout,org.apache.logging.log4j.core.Filter,java.lang.String,java.lang.String,org.apache.logging.log4j.core.config.Configuration).
>>>>>>>>>>>> 2015-10-12 18:55:25,500 DEBUG Calling createAppender on class
>>>>>>>>>>>> org.apache.logging.log4j.core.appender.FileAppender for
>>>> element
>>>>> File
>>>>>>>>>> with
>>>>>>>>>>>> params(name="/data/applogs/data-proxy/logs/app.log",
>>>> name="false",
>>>>>>>>>>>> name="null", name="File", name="false", name="null",
>>>> name="null",
>>>>>>>>>>>> name="null", PatternLayout(%d %-5p [%c{2}] %m%n), null,
>>>>> name="null",
>>>>>>>>>>>> name="null",
>>>> Configuration(jndi:/localhost/WEB-INF/log4j2.xml))
>>>>>>>>>>>> 2015-10-12 18:55:25,504 DEBUG Starting FileManager
>>>>>>>>>>>> /data/applogs/data-proxy/logs/app.log
>>>>>>>>>>>> 2015-10-12 18:55:25,505 DEBUG Built Plugin[name=appender] OK
>>>> from
>>>>>>>>>> factory
>>>>>>>>>>>> method.
>>>>>>>>>>>> 2015-10-12 18:55:25,505 DEBUG Building Plugin[name=layout,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.layout.PatternLayout].
>>>>> Searching
>>>>>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,505 DEBUG Found builder factory method
>>>>>>>>>> [newBuilder]:
>>>>>>>>>>>> public static
>>>>>>>>>> org.apache.logging.log4j.core.layout.PatternLayout$Builder
>>>> org.apache.logging.log4j.core.layout.PatternLayout.newBuilder().
>>>>>>>>>>>> 2015-10-12 18:55:25,507 DEBUG Calling build() on class class
>>>>>>>>>>>> org.apache.logging.log4j.core.layout.PatternLayout$Builder for
>>>>>> element
>>>>>>>>>>>> PatternLayout with params(name="%d %-5p [%c{2}] %m%n",
>>>>>>>>>>>> Configuration(jndi:/localhost/WEB-INF/log4j2.xml), null,
>>>>>> name="null",
>>>>>>>>>>>> name="null", name="null", name="null", name="null")
>>>>>>>>>>>> 2015-10-12 18:55:25,508 DEBUG Built Plugin[name=layout] OK
>>>> from
>>>>>>>> builder
>>>>>>>>>>>> factory method.
>>>>>>>>>>>> 2015-10-12 18:55:25,508 DEBUG Building Plugin[name=appender,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.appender.ConsoleAppender].
>>>>>>>>>> Searching
>>>>>>>>>>>> for builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,510 DEBUG PluginManager 'Converter' found
>>>> 33
>>>>>>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:25,512 DEBUG Found builder factory method
>>>>>>>>>> [newBuilder]:
>>>>>>>>>>>> public static
>>>>>>>>>>>> org.apache.logging.log4j.core.appender.ConsoleAppender$Builder
>>>>> org.apache.logging.log4j.core.appender.ConsoleAppender.newBuilder().
>>>>>>>>>>>> 2015-10-12 18:55:25,519 DEBUG No PluginVisitorStrategy found
>>>> on
>>>>>>>>>>> annotation
>>>>>>>>>>>> [interface
>>>> org.apache.logging.log4j.core.config.plugins.validation.constraints.Required].
>>>>>>>>>>>> Ignoring.
>>>>>>>>>>>> 2015-10-12 18:55:25,520 DEBUG Encountered type
>>>>>>>>>>>> [org.apache.logging.log4j.core.layout.PatternLayout] which can
>>>>> only
>>>>>> be
>>>>>>>>>>>> checked for null.
>>>>>>>>>>>> 2015-10-12 18:55:25,522 DEBUG No PluginVisitorStrategy found
>>>> on
>>>>>>>>>>> annotation
>>>>>>>>>>>> [interface
>>>> org.apache.logging.log4j.core.config.plugins.validation.constraints.Required].
>>>>>>>>>>>> Ignoring.
>>>>>>>>>>>> 2015-10-12 18:55:25,523 DEBUG Encountered type
>>>> [org.apache.logging.log4j.core.appender.ConsoleAppender$Target]
>>>>>> which
>>>>>>>>>> can
>>>>>>>>>>>> only be checked for null.
>>>>>>>>>>>> 2015-10-12 18:55:25,524 DEBUG No PluginVisitorStrategy found
>>>> on
>>>>>>>>>>> annotation
>>>>>>>>>>>> [interface
>>>> org.apache.logging.log4j.core.config.plugins.validation.constraints.Required].
>>>>>>>>>>>> Ignoring.
>>>>>>>>>>>> 2015-10-12 18:55:25,525 DEBUG Calling build() on class class
>>>> org.apache.logging.log4j.core.appender.ConsoleAppender$Builder for
>>>>>>>>>>> element
>>>>>>>>>>>> Console with params(PatternLayout(%d %-5p [%c{2}] %m%n), null,
>>>>>>>>>>>> name="SYSTEM_OUT", name="STDOUT", name="null", name="null")
>>>>>>>>>>>> 2015-10-12 18:55:25,526 DEBUG Built Plugin[name=appender] OK
>>>> from
>>>>>>>>>> builder
>>>>>>>>>>>> factory method.
>>>>>>>>>>>> 2015-10-12 18:55:25,526 DEBUG Building Plugin[name=appenders,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.AppendersPlugin].
>>>>>> Searching
>>>>>>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,527 DEBUG No builder factory method found
>>>> in
>>>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.AppendersPlugin. Going
>>>> to try
>>>>>>>>>>> finding
>>>>>>>>>>>> a factory method instead.
>>>>>>>>>>>> 2015-10-12 18:55:25,527 DEBUG Still building
>>>>> Plugin[name=appenders,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.AppendersPlugin].
>>>>>> Searching
>>>>>>>>>>> for
>>>>>>>>>>>> factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,528 DEBUG Found factory method
>>>>>> [createAppenders]:
>>>>>>>>>>>> public static java.util.concurrent.ConcurrentMap
>>>> org.apache.logging.log4j.core.config.AppendersPlugin.createAppenders(org.apache.logging.log4j.core.Appender[]).
>>>>>>>>>>>> 2015-10-12 18:55:25,530 DEBUG Calling createAppenders on class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.AppendersPlugin for
>>>> element
>>>>>>>>>>> Appenders
>>>>>>>>>>>> with params(={File, STDOUT})
>>>>>>>>>>>> 2015-10-12 18:55:25,532 DEBUG Built Plugin[name=appenders] OK
>>>> from
>>>>>>>>>>> factory
>>>>>>>>>>>> method.
>>>>>>>>>>>> 2015-10-12 18:55:25,532 DEBUG Building
>>>> Plugin[name=AppenderRef,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.AppenderRef].
>>>> Searching
>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,534 DEBUG No builder factory method found
>>>> in
>>>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.AppenderRef. Going to try
>>>>>> finding
>>>>>>>>>> a
>>>>>>>>>>>> factory method instead.
>>>>>>>>>>>> 2015-10-12 18:55:25,535 DEBUG Still building
>>>>>> Plugin[name=AppenderRef,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.AppenderRef].
>>>> Searching
>>>>>> for
>>>>>>>>>>>> factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,536 DEBUG Found factory method
>>>>>>>> [createAppenderRef]:
>>>>>>>>>>>> public static org.apache.logging.log4j.core.config.AppenderRef
>>>> org.apache.logging.log4j.core.config.AppenderRef.createAppenderRef(java.lang.String,org.apache.logging.log4j.Level,org.apache.logging.log4j.core.Filter).
>>>>>>>>>>>> 2015-10-12 18:55:25,538 DEBUG Calling createAppenderRef on
>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.AppenderRef for element
>>>>>>>>>> AppenderRef
>>>>>>>>>>>> with params(name="File", name="null", null)
>>>>>>>>>>>> 2015-10-12 18:55:25,539 DEBUG Built Plugin[name=AppenderRef]
>>>> OK
>>>>> from
>>>>>>>>>>>> factory method.
>>>>>>>>>>>> 2015-10-12 18:55:25,540 DEBUG Building
>>>> Plugin[name=AppenderRef,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.AppenderRef].
>>>> Searching
>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,540 DEBUG No builder factory method found
>>>> in
>>>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.AppenderRef. Going to try
>>>>>> finding
>>>>>>>>>> a
>>>>>>>>>>>> factory method instead.
>>>>>>>>>>>> 2015-10-12 18:55:25,541 DEBUG Still building
>>>>>> Plugin[name=AppenderRef,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.AppenderRef].
>>>> Searching
>>>>>> for
>>>>>>>>>>>> factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,543 DEBUG Found factory method
>>>>>>>> [createAppenderRef]:
>>>>>>>>>>>> public static org.apache.logging.log4j.core.config.AppenderRef
>>>> org.apache.logging.log4j.core.config.AppenderRef.createAppenderRef(java.lang.String,org.apache.logging.log4j.Level,org.apache.logging.log4j.core.Filter).
>>>>>>>>>>>> 2015-10-12 18:55:25,546 DEBUG Calling createAppenderRef on
>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.AppenderRef for element
>>>>>>>>>> AppenderRef
>>>>>>>>>>>> with params(name="STDOUT", name="null", null)
>>>>>>>>>>>> 2015-10-12 18:55:25,547 DEBUG Built Plugin[name=AppenderRef]
>>>> OK
>>>>> from
>>>>>>>>>>>> factory method.
>>>>>>>>>>>> 2015-10-12 18:55:25,548 DEBUG Building Plugin[name=asyncRoot,
>>>> class=org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger].
>>>>>>>>>>>> Searching for builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,551 DEBUG No builder factory method found
>>>> in
>>>>>> class
>>>> org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger.
>>>>>>>> Going
>>>>>>>>>>> to
>>>>>>>>>>>> try finding a factory method instead.
>>>>>>>>>>>> 2015-10-12 18:55:25,552 DEBUG Still building
>>>>> Plugin[name=asyncRoot,
>>>> class=org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger].
>>>>>>>>>>>> Searching for factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,554 DEBUG Found factory method
>>>> [createLogger]:
>>>>>>>>>> public
>>>>>>>>>>>> static org.apache.logging.log4j.core.config.LoggerConfig
>>>> org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger.createLogger(java.lang.String,java.lang.String,java.lang.String,org.apache.logging.log4j.core.config.AppenderRef[],org.apache.logging.log4j.core.config.Property[],org.apache.logging.log4j.core.config.Configuration,org.apache.logging.log4j.core.Filter).
>>>>>>>>>>>> 2015-10-12 18:55:25,559 DEBUG Calling createLogger on class
>>>> org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger
>>>>> for
>>>>>>>>>>>> element asyncRoot with params(name="null", name="info",
>>>>>> name="false",
>>>>>>>>>>>> ={File, STDOUT}, ={},
>>>>>>>>>> Configuration(jndi:/localhost/WEB-INF/log4j2.xml),
>>>>>>>>>>>> null)
>>>>>>>>>>>> 2015-10-12 18:55:25,560 DEBUG Built Plugin[name=asyncRoot] OK
>>>> from
>>>>>>>>>>> factory
>>>>>>>>>>>> method.
>>>>>>>>>>>> 2015-10-12 18:55:25,561 DEBUG Building Plugin[name=loggers,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.LoggersPlugin].
>>>>> Searching
>>>>>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,564 DEBUG No builder factory method found
>>>> in
>>>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.LoggersPlugin. Going to
>>>> try
>>>>>>>>>> finding
>>>>>>>>>>> a
>>>>>>>>>>>> factory method instead.
>>>>>>>>>>>> 2015-10-12 18:55:25,565 DEBUG Still building
>>>> Plugin[name=loggers,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.LoggersPlugin].
>>>>> Searching
>>>>>>>>>> for
>>>>>>>>>>>> factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,565 DEBUG Found factory method
>>>>> [createLoggers]:
>>>>>>>>>>> public
>>>>>>>>>>>> static org.apache.logging.log4j.core.config.Loggers
>>>> org.apache.logging.log4j.core.config.LoggersPlugin.createLoggers(org.apache.logging.log4j.core.config.LoggerConfig[]).
>>>>>>>>>>>> 2015-10-12 18:55:25,566 DEBUG Calling createLoggers on class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.LoggersPlugin for element
>>>>>> Loggers
>>>>>>>>>>> with
>>>>>>>>>>>> params(={root})
>>>>>>>>>>>> 2015-10-12 18:55:25,566 DEBUG Built Plugin[name=loggers] OK
>>>> from
>>>>>>>>>> factory
>>>>>>>>>>>> method.
>>>>>>>>>>>> 2015-10-12 18:55:25,567 TRACE AsyncLoggerConfig[root]
>>>> starting...
>>>>>>>>>>>> 2015-10-12 18:55:25,574 TRACE AsyncLoggerConfigHelper
>>>> creating new
>>>>>>>>>>>> disruptor. Ref count is 1.
>>>>>>>>>>>> 2015-10-12 18:55:25,574 DEBUG property
>>>>>>>>>>> AsyncLoggerConfig.WaitStrategy=null
>>>>>>>>>>>> 2015-10-12 18:55:25,575 DEBUG disruptor event handler uses
>>>>>>>>>>>> BlockingWaitStrategy
>>>>>>>>>>>> 2015-10-12 18:55:25,625 DEBUG Starting AsyncLoggerConfig
>>>> disruptor
>>>>>>>> with
>>>>>>>>>>>> ringbuffer size=262144, waitStrategy=BlockingWaitStrategy,
>>>>>>>>>>>> exceptionHandler=null...
>>>>>>>>>>>> 2015-10-12 18:55:25,627 DEBUG Started configuration
>>>>>>>>>>>> XmlConfiguration[location=jndi:/localhost/WEB-INF/log4j2.xml]
>>>> OK.
>>>>>>>>>>>> 2015-10-12 18:55:25,627 TRACE Stopping
>>>>> org.apache.logging.log4j.core.config.DefaultConfiguration@75c1ada7.
>>>>>> ..
>>>>>>>>>>>> 2015-10-12 18:55:25,628 TRACE AbstractConfiguration stopped 0
>>>>>>>>>>>> AsyncLoggerConfigs.
>>>>>>>>>>>> 2015-10-12 18:55:25,628 TRACE AbstractConfiguration stopped 0
>>>>>>>>>>>> AsyncAppenders.
>>>>>>>>>>>> 2015-10-12 18:55:25,628 TRACE AbstractConfiguration stopped 1
>>>>>>>>>> Appenders.
>>>>>>>>>>>> 2015-10-12 18:55:25,628 TRACE AbstractConfiguration stopped 0
>>>>>> Loggers.
>>>>>>>>>>>> 2015-10-12 18:55:25,629 DEBUG Stopped
>>>> org.apache.logging.log4j.core.config.DefaultConfiguration@75c1ada7
>>>>>> OK
>>>>>>>>>>>> 2015-10-12 18:55:25,634 DEBUG Registering MBean
>>>>>>>>>>>> org.apache.logging.log4j2:type=2090228673
>>>>>>>>>>>> 2015-10-12 18:55:25,642 DEBUG Registering MBean
>>>> org.apache.logging.log4j2:type=2090228673,component=StatusLogger
>>>>>>>>>>>> 2015-10-12 18:55:25,647 DEBUG Registering MBean
>>>>> org.apache.logging.log4j2:type=2090228673,component=ContextSelector
>>>>>>>>>>>> 2015-10-12 18:55:25,649 DEBUG Registering MBean
>>>> org.apache.logging.log4j2:type=2090228673,component=Loggers,name=
>>>>>>>>>>>> 2015-10-12 18:55:25,653 DEBUG Registering MBean
>>>> org.apache.logging.log4j2:type=2090228673,component=Loggers,name=,subtype=RingBuffer
>>>>>>>>>>>> 2015-10-12 18:55:25,657 DEBUG Registering MBean
>>>> org.apache.logging.log4j2:type=2090228673,component=Appenders,name=STDOUT
>>>>>>>>>>>> 2015-10-12 18:55:25,659 DEBUG Registering MBean
>>>>> org.apache.logging.log4j2:type=2090228673,component=Appenders,name=File
>>>>>>>>>>>> 2015-10-12 18:55:25,660 DEBUG LoggerContext[name=2090228673,
>>>>>>>>>>>> org.apache.logging.log4j.core.LoggerContext@4347ede7]
>>>> started OK
>>>>>> with
>>>>>>>>>>>> configuration
>>>>>>>>>>>> XmlConfiguration[location=jndi:/localhost/WEB-INF/log4j2.xml].
>>>>>>>>>>>> 2015-10-12 18:55:26,198 DEBUG Starting RollingFileManager
>>>>>>>>>>>> /data/applogs/pigeon/pigeon.data-proxy.log
>>>>>>>>>>>> 2015-10-12 18:55:26,200 DEBUG PluginManager 'FileConverter'
>>>> found
>>>>> 2
>>>>>>>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:26,203 TRACE PatternProcessor.getNextTime
>>>>> returning
>>>>>>>>>>>> 2015/10/13-00:00:00.000, nextFileTime=2015/10/12-00:00:00.000,
>>>>>>>>>>>> prevFileTime=1970/01/01-08:00:00.000,
>>>>>> current=2015/10/12-18:55:26.202,
>>>>>>>>>>>> freq=DAILY
>>>>>>>>>>>> 2015-10-12 18:55:26,204 TRACE PatternProcessor.getNextTime
>>>>> returning
>>>>>>>>>>>> 2015/10/13-00:00:00.000, nextFileTime=2015/10/12-00:00:00.000,
>>>>>>>>>>>> prevFileTime=2015/10/12-00:00:00.000,
>>>>>> current=2015/10/12-18:55:26.203,
>>>>>>>>>>>> freq=DAILY
>>>>>>>>>>>> 2015-10-12 18:55:26,204 DEBUG Starting OutputStreamManager
>>>>>> SYSTEM_ERR
>>>>>>>>>>>> 2015-10-12 18:55:26,207 DEBUG Starting RollingFileManager
>>>>>>>>>>>> /data/applogs/pigeon/pigeon.data-proxy.access.log
>>>>>>>>>>>> 2015-10-12 18:55:26,207 DEBUG PluginManager 'FileConverter'
>>>> found
>>>>> 2
>>>>>>>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:26,208 TRACE PatternProcessor.getNextTime
>>>>> returning
>>>>>>>>>>>> 2015/09/30-00:00:00.000, nextFileTime=2015/09/29-00:00:00.000,
>>>>>>>>>>>> prevFileTime=1970/01/01-08:00:00.000,
>>>>>> current=2015/10/12-18:55:26.208,
>>>>>>>>>>>> freq=DAILY
>>>>>>>>>>>> 2015-10-12 18:55:26,209 TRACE PatternProcessor.getNextTime
>>>>> returning
>>>>>>>>>>>> 2015/09/30-00:00:00.000, nextFileTime=2015/09/29-00:00:00.000,
>>>>>>>>>>>> prevFileTime=2015/09/29-00:00:00.000,
>>>>>> current=2015/10/12-18:55:26.209,
>>>>>>>>>>>> freq=DAILY
>>>>>>>>>>>> 2015-10-12 18:55:26,239 DEBUG Using default SystemClock for
>>>>>> timestamps
>>>>>>>>> 
>>>>>>>>> 
>>>>>>>>> 
>>>>>>>>> --
>>>>>>>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>>>>>>>> Java Persistence with Hibernate, Second Edition
>>>>>>>>> <http://www.manning.com/bauer3/>
>>>>>>>>> JUnit in Action, Second Edition <
>>>> http://www.manning.com/tahchiev/>
>>>>>>>>> Spring Batch in Action <http://www.manning.com/templier/>
>>>>>>>>> Blog: http://garygregory.wordpress.com
>>>>>>>>> Home: http://garygregory.com/
>>>>>>>>> Tweet! http://twitter.com/GaryGregory
>>>> ---------------------------------------------------------------------
>>>>>>>> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
>>>>>>>> For additional commands, e-mail:
>>>> log4j-user-help@logging.apache.org
>>>>>> 
>>>>>> ---------------------------------------------------------------------
>>>>>> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
>>>>>> For additional commands, e-mail: log4j-user-help@logging.apache.org
>>>>> 
>>>>> 
>>>>> --
>>>>> [image: MagineTV]
>>>>> 
>>>>> *Mikael Ståldal*
>>>>> Senior software developer
>>>>> 
>>>>> *Magine TV*
>>>>> mikael.staldal@magine.com
>>>>> Regeringsgatan 25  | 111 53 Stockholm, Sweden  |   www.magine.com
>>>>> 
>>>>> Privileged and/or Confidential Information may be contained in this
>>>>> message. If you are not the addressee indicated in this message
>>>>> (or responsible for delivery of the message to such a person), you may
>>>> not
>>>>> copy or deliver this message to anyone. In such case,
>>>>> you should destroy this message and kindly notify the sender by reply
>>>>> email.
>>>> 
>>>> 
>>>> 
>>>> --
>>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>>> Java Persistence with Hibernate, Second Edition
>>>> <http://www.manning.com/bauer3/>
>>>> JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
>>>> Spring Batch in Action <http://www.manning.com/templier/>
>>>> Blog: http://garygregory.wordpress.com
>>>> Home: http://garygregory.com/
>>>> Tweet! http://twitter.com/GaryGregory
>> 

Re: Bizarre performance in log4j2

Posted by Remko Popma <re...@gmail.com>.
That matches my expectation. The ring buffer can handle bursts of events, but if the sustained logging rate is faster than the appender can handle, the ring buffer will fill up and you will end up logging at the speed of the appender. 
So if you log a lot, you still need to configure a fast appender like RandomAccessFileAppender. 

Sent from my iPhone

> On 2015/12/10, at 18:09, Strong Su <lo...@gmail.com> wrote:
> 
> Hello everyone,
> We re-test log4j2's performance in our system from the very beginning. In
> our case, there two factors which will decrease the performance heavily.
> 1. %c or %class
>    As Remko said, the information of location(you can see the log4j2.xml
> above)  will hurt async logger badly. And when I remove it, the performance
> returns normal.
> 2. ringBuffer
>    My mentor, Erik Fang(fmerik@gmail.com), changed the source code of
> AsyncLogger and add a little counter to measure the status of ringBuffer.
> When a request came, the counter will plus 1 if the ringBuffer is full for
> that moment. And calculate the ratio(counter/requestsNum), call it
> fullRatio, when all the requests are done.
>    It turns out that when fullRatio becomes high, the performance(QPS)
> will drop very quickly. I test it in our system and it's confirmed.
>    I print a log whenever a request comes in my origin test and I change
> the log's size like 10bytes, 100bytes and so on. The performance of
> sync_log4j2 and async_log4j2 seemed normal(around 30k) and it's almost the
> same as the performance when I don't print logs, which is great, and
> fullRatio of async_log4j2 is lower than 1%. But as I increase the size of
> one log(more than 1Kb) and number of threads, fullRatio can be up to more
> than 8% and QPS of async_log4j2 drops to 19k and QPS of sync_log4j2 is
> still 26k. As a result, we think factors, like extremely long logs and
> numerous threads, which may make the speed of disruptor's consumer(appender
> in log4j2) lower than disruptor's producer(logger in log4j2) can also
> influence the performance in async_log4j2.
> 
> PS:
> During the Test.
> I insert a log in a http request function on server side. And I start
> requests continually on client side through hundreds of threads.
> I measure the performance through QPS because server has to print a log
> whenever it receive a request. The time delayed by logging will influence
> QPS heavily.
> I continually increasing the number of client until QPS reaches the limit.
> The highest QPS appears when the number of client is about 400 but QPS will
> drop and fullRatio will increase after that.
> 
> Thank Erik and Remko very much.
> 
> Best Regards,
> Dylan Su
> 
> 
> 
> 
> 
> 
>> On Tue, Oct 20, 2015 at 3:38 PM, Strong Su <lo...@gmail.com> wrote:
>> 
>> Hello everyone,
>> I take a deep look at our project and found one of our third dependencies
>> was using log4j2. It is using APIs of log4j2 instead of configuration files
>> but it can recognise and use my log4j2.xml.
>> I wrote a simple example to illustrate how log4j2 be added in the third
>> dependency.
>> 
>> *Function_A:*
>> 
>> public void function_A(){
>> 
>>        LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
>> 
>>        Configuration config = ctx.getConfiguration();
>> 
>>        Layout layout = PatternLayout.createLayout(
>> 
>>                "%d{yyyy-MM-dd HH:mm:ss} [%t] %-5level %class{36} %L %M -
>> %msg%xEx%n", config, null, null, true, false, null, null);
>> 
>> 
>>        ConsoleAppender consoleAppender = ConsoleAppender.createAppender(
>> layout, null, "SYSTEM_OUT", "consoleAppender", "false", "false");
>> 
>>        AppenderRef consoleRef = AppenderRef.createAppenderRef(
>> "consoleAppender", Level.INFO, null);
>> 
>>        AppenderRef[] crefs = new AppenderRef[] { consoleRef };
>> 
>>        consoleAppender.start();
>> 
>>        config.addAppender(consoleAppender);
>> 
>> 
>> 
>>        AsyncAppender asyncAppender = AsyncAppender.createAppender(crefs,
>> null,
>> 
>>                true, 128, "asyncAppender", false, null, config, false);
>> 
>>        AppenderRef accessRef = AppenderRef.createAppenderRef(
>> "asyncAppender", Level.INFO, null);
>> 
>>        AppenderRef[] arefs = new AppenderRef[] { accessRef };
>> 
>>        asyncAppender.start();
>> 
>>        config.addAppender(asyncAppender);
>> 
>> 
>>        LoggerConfig loggerConfig = LoggerConfig.createLogger("false",
>> Level.INFO, "com.TestMain", "true", arefs, null, config, null);
>> 
>>        loggerConfig.addAppender(consoleAppender, Level.INFO, null);
>> 
>>        config.addLogger("com.TestMain", loggerConfig);
>> 
>>        Logger LOG = ctx.getLogger("com.TestMain");
>> 
>> }
>> 
>> *Log4j2.xml:*
>> 
>> <?xml version="1.0" encoding="UTF-8"?>
>> 
>> <Configuration status="warn">
>> 
>>    <Appenders>
>> 
>>        <Console name="Console" target="SYSTEM_OUT">
>> 
>>            <PatternLayout pattern="%d %-5p %logger{36}  %msg%n"/>
>> 
>>        </Console>
>> 
>>    </Appenders>
>> 
>>    <Loggers>
>> 
>>        <Root level="info">
>> 
>>            <AppenderRef ref="Console" />
>> 
>>        </Root>
>> 
>>    </Loggers>
>> 
>> </Configuration>
>> 
>> 
>> I will call the appender in function_A as appender_API, and call the
>> appender from log4j2.xml as appender_XML.
>> 
>> Through my tests to print log using logger, named LOG, from function_A. I
>> found these phenomenons:
>> 
>> 1) just use the function_A and log4j2.xml above
>> 
>>    logs will be printed by appender_API
>> 
>> 2) add <logger name="com.TestMain" level="info"><AppenderRef
>> ref="Console"/></logger> in tag <Loggers> of log4j2.xml
>> 
>>    logs will be printed by appender_XML twice although I have set
>> additivity="false" when I create logger in function_A
>> 
>> 3) add <logger name="com.TestMain" level="info"
>> additivity="false"><AppenderRef ref="Console"/></logger> in tag <Loggers>
>> of log4j2.xml
>> 
>>    logs will be printed by appender_XML once
>> 
>> 
>> How can I explain these? All I can think is that the configuration of
>> logger from log4j2.xml covers the configuration from function_A. But
>> I'm little confusion about the load sequence between different loggers.
>> 
>> 
>> Besides, the configuration of logger named "com.TestMain" has location
>> information and it sets includeLocation="true".
>> 
>> To test async logger in log4j2, I just change <root> to <asyncRoot>
>> comparing the <Loggers>'s configs of log4j2.xml from above and it turns out
>> a even worse performance in my early tests. Will the combination below
>> influence the performance if these two loggers print logs in the same file?
>> 
>> 1) sync logger, async appender and includeLocation="true" to print logs
>> from function_A
>> 
>> 2) asyncRoot, sync appender and includeLocation="false" to print other logs
>> 
>> Will it be difference if they print logs in two separate files?
>> 
>> 
>> Thank you very much.
>> 
>> Best regards,
>> 
>> Dylan Su
>> 
>> 
>> 
>> 
>> 
>>> On Fri, Oct 16, 2015 at 7:21 PM, Strong Su <lo...@gmail.com> wrote:
>>> 
>>> Hello everyone,
>>> 
>>> It takes me sometime to make sure that I have removed all log4j-1.2.16
>>> and slf4j-log4j12.
>>> It became better but not good enough.
>>> Since sync log4j2 has already performed much better than log4j1, we
>>> decided to use sync log4j2 first.
>>> And I will start a fresh test over async log4j2 from beginning to
>>> checkout where the problem is.
>>> 
>>> I will update this thread or link this problem to a new thread when the
>>> performance becomes normal.
>>> 
>>> Thank you very much for the advices during these days.
>>> 
>>> Best regards,
>>> Dylan Su
>>> 
>>>> On Wed, Oct 14, 2015 at 4:58 PM, Strong Su <lo...@gmail.com> wrote:
>>>> 
>>>> 
>>>> ---------- Forwarded message ----------
>>>> From: Gary Gregory <ga...@gmail.com>
>>>> Date: Tue, Oct 13, 2015 at 9:58 PM
>>>> Subject: Re: Bizarre performance in log4j2
>>>> To: Log4J Users List <lo...@logging.apache.org>
>>>> 
>>>> 
>>>> You can check with:
>>>> 
>>>> mvn dependency:tree
>>>> 
>>>> Gary
>>>> 
>>>> On Tue, Oct 13, 2015 at 1:24 AM, Mikael Ståldal <
>>>> mikael.staldal@magine.com>
>>>> wrote:
>>>> 
>>>>> ...and make sure that no 3rd party dependencies brings them in.
>>>>> 
>>>>> On Tue, Oct 13, 2015 at 8:22 AM, Remko Popma <re...@gmail.com>
>>>>> wrote:
>>>>> 
>>>>>> Please remove log4j-1.2.16 and replace it with log4j-1.2-api version
>>>> 2.3.
>>>>>> 
>>>>>> Also remove slf4j-log4j12 and add log4j-slf4j-impl version 2.3.
>>>>>> 
>>>>>> Sent from my iPhone
>>>>>> 
>>>>>>> On 2015/10/13, at 14:39, Strong Su <lo...@gmail.com> wrote:
>>>>>>> 
>>>>>>> Here is my pom.xml for logging:
>>>>>>> 
>>>>>>> <dependency>
>>>>>>>   <groupId>log4j</groupId>
>>>>>>>   <artifactId>log4j</artifactId>
>>>>>>>   <version>1.2.16</version>
>>>>>>> </dependency>
>>>>>>> <dependency>
>>>>>>>   <groupId>org.slf4j</groupId>
>>>>>>>   <artifactId>slf4j-log4j12</artifactId>
>>>>>>>   <version>1.5.11</version>
>>>>>>> </dependency>
>>>>>>> <dependency>
>>>>>>>   <groupId>org.slf4j</groupId>
>>>>>>>   <artifactId>slf4j-api</artifactId>
>>>>>>>   <version>1.5.11</version>
>>>>>>> </dependency>
>>>>>>> <dependency>
>>>>>>>   <groupId>org.apache.logging.log4j</groupId>
>>>>>>>   <artifactId>log4j-api</artifactId>
>>>>>>>   <version>2.3</version>
>>>>>>> </dependency>
>>>>>>> <dependency>
>>>>>>>   <groupId>org.apache.logging.log4j</groupId>
>>>>>>>   <artifactId>log4j-core</artifactId>
>>>>>>>   <version>2.3</version>
>>>>>>> </dependency>
>>>>>>> <dependency>
>>>>>>>   <groupId>org.apache.logging.log4j</groupId>
>>>>>>>   <artifactId>log4j-web</artifactId>
>>>>>>>   <version>2.3</version>
>>>>>>> </dependency>
>>>>>>> <dependency>
>>>>>>>   <groupId>com.lmax</groupId>
>>>>>>>   <artifactId>disruptor</artifactId>
>>>>>>>   <version>3.2.0</version>
>>>>>>> </dependency>
>>>>>>> 
>>>>>>> 
>>>>>>>> On Tue, Oct 13, 2015 at 12:22 PM, Remko Popma <
>>>> remko.popma@gmail.com>
>>>>>> wrote:
>>>>>>>> 
>>>>>>>> For log4j1, are you using the log4j-1.2-api-2.x.jar? And
>>>> similarly the
>>>>>>>> log4j-slf4j-impl-2.x.jar for SLF4J? (Just checking...)
>>>>>>>> 
>>>>>>>> Sent from my iPhone
>>>>>>>> 
>>>>>>>>> On 2015/10/13, at 11:43, Gary Gregory <ga...@gmail.com>
>>>>> wrote:
>>>>>>>>> 
>>>>>>>>> Can you use 2.4?
>>>>>>>>> 
>>>>>>>>> Gary
>>>>>>>>> 
>>>>>>>>>> On Mon, Oct 12, 2015 at 6:56 PM, Strong Su <lovelosew@gmail.com
>>>>> 
>>>>>> wrote:
>>>>>>>>>> 
>>>>>>>>>> I'm using Log4j 2.3 and Disruptor 3.2.
>>>>>>>>>> Because of third party package like spring, I have to use Log4j
>>>> 1.2
>>>>>> and
>>>>>>>>>> slf4j 1.5 too.
>>>>>>>>>> 
>>>>>>>>>> 
>>>>>>>>>> On Tue, Oct 13, 2015 at 7:15 AM, Remko Popma <
>>>> remko.popma@gmail.com
>>>>>> 
>>>>>>>>>> wrote:
>>>>>>>>>> 
>>>>>>>>>>> Output looks ok.
>>>>>>>>>>> Sleep was the default wait strategy but has been changed to
>>>> Block a
>>>>>>>> long
>>>>>>>>>>> time ago. Looks like the docs are out of date. Thanks for
>>>> drawing
>>>>> my
>>>>>>>>>>> attention to this.
>>>>>>>>>>> 
>>>>>>>>>>> I don't understand why changing the includeLocation does not
>>>> make a
>>>>>>>>>>> difference in performance. You should see a large improvement.
>>>>>>>>>>> Which Log4j version are you using?
>>>>>>>>>>> 
>>>>>>>>>>> 
>>>>>>>>>>> 
>>>>>>>>>>>> On Mon, Oct 12, 2015 at 12:58 PM, Strong Su <
>>>> lovelosew@gmail.com>
>>>>>>>> wrote:
>>>>>>>>>>>> 
>>>>>>>>>>>> Here is my console debug with status="trace".
>>>>>>>>>>>> I found that log4j2 didn't get SleepWaitingStrategy by default
>>>>> and I
>>>>>>>>>>> didn't
>>>>>>>>>>>> find includeLocation in console.
>>>>>>>>>>>> 
>>>>>>>>>>>> 
>>>>>>>>>>>> 2015-10-12 18:55:25,424 DEBUG Starting
>>>>>> LoggerContext[name=2090228673]
>>>>>>>>>>> from
>>>>>>>>>>>> configuration at jndi:/localhost/WEB-INF/log4j2.xml
>>>>>>>>>>>> 2015-10-12 18:55:25,425 DEBUG Starting
>>>>>> LoggerContext[name=2090228673,
>>>>>>>>>>>> org.apache.logging.log4j.core.LoggerContext@4347ede7] with
>>>>>>>>>> configuration
>>>> XmlConfiguration[location=jndi:/localhost/WEB-INF/log4j2.xml]...
>>>>>>>>>>>> 2015-10-12 18:55:25,427 DEBUG Shutdown hook enabled.
>>>> Registering a
>>>>>> new
>>>>>>>>>>> one.
>>>>>>>>>>>> 2015-10-12 18:55:25,430 DEBUG Starting configuration
>>>>>>>>>>>> XmlConfiguration[location=jndi:/localhost/WEB-INF/log4j2.xml]
>>>>>>>>>>>> 2015-10-12 18:55:25,432 DEBUG PluginManager 'Core' found 70
>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:25,433 DEBUG PluginManager 'Level' found 0
>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:25,438 DEBUG PluginManager 'Lookup' found 11
>>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:25,441 DEBUG Building Plugin[name=layout,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.layout.PatternLayout].
>>>>> Searching
>>>>>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,445 DEBUG Found builder factory method
>>>>>>>>>> [newBuilder]:
>>>>>>>>>>>> public static
>>>>>>>>>> org.apache.logging.log4j.core.layout.PatternLayout$Builder
>>>> org.apache.logging.log4j.core.layout.PatternLayout.newBuilder().
>>>>>>>>>>>> 2015-10-12 18:55:25,458 DEBUG TypeConverterRegistry
>>>> initializing.
>>>>>>>>>>>> 2015-10-12 18:55:25,458 DEBUG PluginManager 'TypeConverter'
>>>> found
>>>>> 21
>>>>>>>>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:25,480 DEBUG Calling build() on class class
>>>>>>>>>>>> org.apache.logging.log4j.core.layout.PatternLayout$Builder for
>>>>>> element
>>>>>>>>>>>> PatternLayout with params(name="%d %-5p [%c{2}] %m%n",
>>>>>>>>>>>> Configuration(jndi:/localhost/WEB-INF/log4j2.xml), null,
>>>>>> name="null",
>>>>>>>>>>>> name="null", name="null", name="null", name="null")
>>>>>>>>>>>> 2015-10-12 18:55:25,481 DEBUG PluginManager 'Converter' found
>>>> 33
>>>>>>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:25,482 DEBUG Built Plugin[name=layout] OK
>>>> from
>>>>>>>> builder
>>>>>>>>>>>> factory method.
>>>>>>>>>>>> 2015-10-12 18:55:25,483 DEBUG Building Plugin[name=appender,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.appender.FileAppender].
>>>>>> Searching
>>>>>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,485 DEBUG No builder factory method found
>>>> in
>>>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.appender.FileAppender. Going to
>>>> try
>>>>>>>>>>> finding a
>>>>>>>>>>>> factory method instead.
>>>>>>>>>>>> 2015-10-12 18:55:25,486 DEBUG Still building
>>>> Plugin[name=appender,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.appender.FileAppender].
>>>>>> Searching
>>>>>>>>>> for
>>>>>>>>>>>> factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,486 DEBUG Found factory method
>>>>> [createAppender]:
>>>>>>>>>>> public
>>>>>>>>>>>> static org.apache.logging.log4j.core.appender.FileAppender
>>>> org.apache.logging.log4j.core.appender.FileAppender.createAppender(java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,java.lang.String,org.apache.logging.log4j.core.Layout,org.apache.logging.log4j.core.Filter,java.lang.String,java.lang.String,org.apache.logging.log4j.core.config.Configuration).
>>>>>>>>>>>> 2015-10-12 18:55:25,500 DEBUG Calling createAppender on class
>>>>>>>>>>>> org.apache.logging.log4j.core.appender.FileAppender for
>>>> element
>>>>> File
>>>>>>>>>> with
>>>>>>>>>>>> params(name="/data/applogs/data-proxy/logs/app.log",
>>>> name="false",
>>>>>>>>>>>> name="null", name="File", name="false", name="null",
>>>> name="null",
>>>>>>>>>>>> name="null", PatternLayout(%d %-5p [%c{2}] %m%n), null,
>>>>> name="null",
>>>>>>>>>>>> name="null",
>>>> Configuration(jndi:/localhost/WEB-INF/log4j2.xml))
>>>>>>>>>>>> 2015-10-12 18:55:25,504 DEBUG Starting FileManager
>>>>>>>>>>>> /data/applogs/data-proxy/logs/app.log
>>>>>>>>>>>> 2015-10-12 18:55:25,505 DEBUG Built Plugin[name=appender] OK
>>>> from
>>>>>>>>>> factory
>>>>>>>>>>>> method.
>>>>>>>>>>>> 2015-10-12 18:55:25,505 DEBUG Building Plugin[name=layout,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.layout.PatternLayout].
>>>>> Searching
>>>>>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,505 DEBUG Found builder factory method
>>>>>>>>>> [newBuilder]:
>>>>>>>>>>>> public static
>>>>>>>>>> org.apache.logging.log4j.core.layout.PatternLayout$Builder
>>>> org.apache.logging.log4j.core.layout.PatternLayout.newBuilder().
>>>>>>>>>>>> 2015-10-12 18:55:25,507 DEBUG Calling build() on class class
>>>>>>>>>>>> org.apache.logging.log4j.core.layout.PatternLayout$Builder for
>>>>>> element
>>>>>>>>>>>> PatternLayout with params(name="%d %-5p [%c{2}] %m%n",
>>>>>>>>>>>> Configuration(jndi:/localhost/WEB-INF/log4j2.xml), null,
>>>>>> name="null",
>>>>>>>>>>>> name="null", name="null", name="null", name="null")
>>>>>>>>>>>> 2015-10-12 18:55:25,508 DEBUG Built Plugin[name=layout] OK
>>>> from
>>>>>>>> builder
>>>>>>>>>>>> factory method.
>>>>>>>>>>>> 2015-10-12 18:55:25,508 DEBUG Building Plugin[name=appender,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.appender.ConsoleAppender].
>>>>>>>>>> Searching
>>>>>>>>>>>> for builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,510 DEBUG PluginManager 'Converter' found
>>>> 33
>>>>>>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:25,512 DEBUG Found builder factory method
>>>>>>>>>> [newBuilder]:
>>>>>>>>>>>> public static
>>>>>>>>>>>> org.apache.logging.log4j.core.appender.ConsoleAppender$Builder
>>>>> org.apache.logging.log4j.core.appender.ConsoleAppender.newBuilder().
>>>>>>>>>>>> 2015-10-12 18:55:25,519 DEBUG No PluginVisitorStrategy found
>>>> on
>>>>>>>>>>> annotation
>>>>>>>>>>>> [interface
>>>> org.apache.logging.log4j.core.config.plugins.validation.constraints.Required].
>>>>>>>>>>>> Ignoring.
>>>>>>>>>>>> 2015-10-12 18:55:25,520 DEBUG Encountered type
>>>>>>>>>>>> [org.apache.logging.log4j.core.layout.PatternLayout] which can
>>>>> only
>>>>>> be
>>>>>>>>>>>> checked for null.
>>>>>>>>>>>> 2015-10-12 18:55:25,522 DEBUG No PluginVisitorStrategy found
>>>> on
>>>>>>>>>>> annotation
>>>>>>>>>>>> [interface
>>>> org.apache.logging.log4j.core.config.plugins.validation.constraints.Required].
>>>>>>>>>>>> Ignoring.
>>>>>>>>>>>> 2015-10-12 18:55:25,523 DEBUG Encountered type
>>>> [org.apache.logging.log4j.core.appender.ConsoleAppender$Target]
>>>>>> which
>>>>>>>>>> can
>>>>>>>>>>>> only be checked for null.
>>>>>>>>>>>> 2015-10-12 18:55:25,524 DEBUG No PluginVisitorStrategy found
>>>> on
>>>>>>>>>>> annotation
>>>>>>>>>>>> [interface
>>>> org.apache.logging.log4j.core.config.plugins.validation.constraints.Required].
>>>>>>>>>>>> Ignoring.
>>>>>>>>>>>> 2015-10-12 18:55:25,525 DEBUG Calling build() on class class
>>>> org.apache.logging.log4j.core.appender.ConsoleAppender$Builder for
>>>>>>>>>>> element
>>>>>>>>>>>> Console with params(PatternLayout(%d %-5p [%c{2}] %m%n), null,
>>>>>>>>>>>> name="SYSTEM_OUT", name="STDOUT", name="null", name="null")
>>>>>>>>>>>> 2015-10-12 18:55:25,526 DEBUG Built Plugin[name=appender] OK
>>>> from
>>>>>>>>>> builder
>>>>>>>>>>>> factory method.
>>>>>>>>>>>> 2015-10-12 18:55:25,526 DEBUG Building Plugin[name=appenders,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.AppendersPlugin].
>>>>>> Searching
>>>>>>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,527 DEBUG No builder factory method found
>>>> in
>>>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.AppendersPlugin. Going
>>>> to try
>>>>>>>>>>> finding
>>>>>>>>>>>> a factory method instead.
>>>>>>>>>>>> 2015-10-12 18:55:25,527 DEBUG Still building
>>>>> Plugin[name=appenders,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.AppendersPlugin].
>>>>>> Searching
>>>>>>>>>>> for
>>>>>>>>>>>> factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,528 DEBUG Found factory method
>>>>>> [createAppenders]:
>>>>>>>>>>>> public static java.util.concurrent.ConcurrentMap
>>>> org.apache.logging.log4j.core.config.AppendersPlugin.createAppenders(org.apache.logging.log4j.core.Appender[]).
>>>>>>>>>>>> 2015-10-12 18:55:25,530 DEBUG Calling createAppenders on class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.AppendersPlugin for
>>>> element
>>>>>>>>>>> Appenders
>>>>>>>>>>>> with params(={File, STDOUT})
>>>>>>>>>>>> 2015-10-12 18:55:25,532 DEBUG Built Plugin[name=appenders] OK
>>>> from
>>>>>>>>>>> factory
>>>>>>>>>>>> method.
>>>>>>>>>>>> 2015-10-12 18:55:25,532 DEBUG Building
>>>> Plugin[name=AppenderRef,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.AppenderRef].
>>>> Searching
>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,534 DEBUG No builder factory method found
>>>> in
>>>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.AppenderRef. Going to try
>>>>>> finding
>>>>>>>>>> a
>>>>>>>>>>>> factory method instead.
>>>>>>>>>>>> 2015-10-12 18:55:25,535 DEBUG Still building
>>>>>> Plugin[name=AppenderRef,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.AppenderRef].
>>>> Searching
>>>>>> for
>>>>>>>>>>>> factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,536 DEBUG Found factory method
>>>>>>>> [createAppenderRef]:
>>>>>>>>>>>> public static org.apache.logging.log4j.core.config.AppenderRef
>>>> org.apache.logging.log4j.core.config.AppenderRef.createAppenderRef(java.lang.String,org.apache.logging.log4j.Level,org.apache.logging.log4j.core.Filter).
>>>>>>>>>>>> 2015-10-12 18:55:25,538 DEBUG Calling createAppenderRef on
>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.AppenderRef for element
>>>>>>>>>> AppenderRef
>>>>>>>>>>>> with params(name="File", name="null", null)
>>>>>>>>>>>> 2015-10-12 18:55:25,539 DEBUG Built Plugin[name=AppenderRef]
>>>> OK
>>>>> from
>>>>>>>>>>>> factory method.
>>>>>>>>>>>> 2015-10-12 18:55:25,540 DEBUG Building
>>>> Plugin[name=AppenderRef,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.AppenderRef].
>>>> Searching
>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,540 DEBUG No builder factory method found
>>>> in
>>>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.AppenderRef. Going to try
>>>>>> finding
>>>>>>>>>> a
>>>>>>>>>>>> factory method instead.
>>>>>>>>>>>> 2015-10-12 18:55:25,541 DEBUG Still building
>>>>>> Plugin[name=AppenderRef,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.AppenderRef].
>>>> Searching
>>>>>> for
>>>>>>>>>>>> factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,543 DEBUG Found factory method
>>>>>>>> [createAppenderRef]:
>>>>>>>>>>>> public static org.apache.logging.log4j.core.config.AppenderRef
>>>> org.apache.logging.log4j.core.config.AppenderRef.createAppenderRef(java.lang.String,org.apache.logging.log4j.Level,org.apache.logging.log4j.core.Filter).
>>>>>>>>>>>> 2015-10-12 18:55:25,546 DEBUG Calling createAppenderRef on
>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.AppenderRef for element
>>>>>>>>>> AppenderRef
>>>>>>>>>>>> with params(name="STDOUT", name="null", null)
>>>>>>>>>>>> 2015-10-12 18:55:25,547 DEBUG Built Plugin[name=AppenderRef]
>>>> OK
>>>>> from
>>>>>>>>>>>> factory method.
>>>>>>>>>>>> 2015-10-12 18:55:25,548 DEBUG Building Plugin[name=asyncRoot,
>>>> class=org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger].
>>>>>>>>>>>> Searching for builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,551 DEBUG No builder factory method found
>>>> in
>>>>>> class
>>>> org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger.
>>>>>>>> Going
>>>>>>>>>>> to
>>>>>>>>>>>> try finding a factory method instead.
>>>>>>>>>>>> 2015-10-12 18:55:25,552 DEBUG Still building
>>>>> Plugin[name=asyncRoot,
>>>> class=org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger].
>>>>>>>>>>>> Searching for factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,554 DEBUG Found factory method
>>>> [createLogger]:
>>>>>>>>>> public
>>>>>>>>>>>> static org.apache.logging.log4j.core.config.LoggerConfig
>>>> org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger.createLogger(java.lang.String,java.lang.String,java.lang.String,org.apache.logging.log4j.core.config.AppenderRef[],org.apache.logging.log4j.core.config.Property[],org.apache.logging.log4j.core.config.Configuration,org.apache.logging.log4j.core.Filter).
>>>>>>>>>>>> 2015-10-12 18:55:25,559 DEBUG Calling createLogger on class
>>>> org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger
>>>>> for
>>>>>>>>>>>> element asyncRoot with params(name="null", name="info",
>>>>>> name="false",
>>>>>>>>>>>> ={File, STDOUT}, ={},
>>>>>>>>>> Configuration(jndi:/localhost/WEB-INF/log4j2.xml),
>>>>>>>>>>>> null)
>>>>>>>>>>>> 2015-10-12 18:55:25,560 DEBUG Built Plugin[name=asyncRoot] OK
>>>> from
>>>>>>>>>>> factory
>>>>>>>>>>>> method.
>>>>>>>>>>>> 2015-10-12 18:55:25,561 DEBUG Building Plugin[name=loggers,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.LoggersPlugin].
>>>>> Searching
>>>>>>>>>> for
>>>>>>>>>>>> builder factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,564 DEBUG No builder factory method found
>>>> in
>>>>>> class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.LoggersPlugin. Going to
>>>> try
>>>>>>>>>> finding
>>>>>>>>>>> a
>>>>>>>>>>>> factory method instead.
>>>>>>>>>>>> 2015-10-12 18:55:25,565 DEBUG Still building
>>>> Plugin[name=loggers,
>>>>>>>>>>>> class=org.apache.logging.log4j.core.config.LoggersPlugin].
>>>>> Searching
>>>>>>>>>> for
>>>>>>>>>>>> factory method...
>>>>>>>>>>>> 2015-10-12 18:55:25,565 DEBUG Found factory method
>>>>> [createLoggers]:
>>>>>>>>>>> public
>>>>>>>>>>>> static org.apache.logging.log4j.core.config.Loggers
>>>> org.apache.logging.log4j.core.config.LoggersPlugin.createLoggers(org.apache.logging.log4j.core.config.LoggerConfig[]).
>>>>>>>>>>>> 2015-10-12 18:55:25,566 DEBUG Calling createLoggers on class
>>>>>>>>>>>> org.apache.logging.log4j.core.config.LoggersPlugin for element
>>>>>> Loggers
>>>>>>>>>>> with
>>>>>>>>>>>> params(={root})
>>>>>>>>>>>> 2015-10-12 18:55:25,566 DEBUG Built Plugin[name=loggers] OK
>>>> from
>>>>>>>>>> factory
>>>>>>>>>>>> method.
>>>>>>>>>>>> 2015-10-12 18:55:25,567 TRACE AsyncLoggerConfig[root]
>>>> starting...
>>>>>>>>>>>> 2015-10-12 18:55:25,574 TRACE AsyncLoggerConfigHelper
>>>> creating new
>>>>>>>>>>>> disruptor. Ref count is 1.
>>>>>>>>>>>> 2015-10-12 18:55:25,574 DEBUG property
>>>>>>>>>>> AsyncLoggerConfig.WaitStrategy=null
>>>>>>>>>>>> 2015-10-12 18:55:25,575 DEBUG disruptor event handler uses
>>>>>>>>>>>> BlockingWaitStrategy
>>>>>>>>>>>> 2015-10-12 18:55:25,625 DEBUG Starting AsyncLoggerConfig
>>>> disruptor
>>>>>>>> with
>>>>>>>>>>>> ringbuffer size=262144, waitStrategy=BlockingWaitStrategy,
>>>>>>>>>>>> exceptionHandler=null...
>>>>>>>>>>>> 2015-10-12 18:55:25,627 DEBUG Started configuration
>>>>>>>>>>>> XmlConfiguration[location=jndi:/localhost/WEB-INF/log4j2.xml]
>>>> OK.
>>>>>>>>>>>> 2015-10-12 18:55:25,627 TRACE Stopping
>>>>> org.apache.logging.log4j.core.config.DefaultConfiguration@75c1ada7.
>>>>>> ..
>>>>>>>>>>>> 2015-10-12 18:55:25,628 TRACE AbstractConfiguration stopped 0
>>>>>>>>>>>> AsyncLoggerConfigs.
>>>>>>>>>>>> 2015-10-12 18:55:25,628 TRACE AbstractConfiguration stopped 0
>>>>>>>>>>>> AsyncAppenders.
>>>>>>>>>>>> 2015-10-12 18:55:25,628 TRACE AbstractConfiguration stopped 1
>>>>>>>>>> Appenders.
>>>>>>>>>>>> 2015-10-12 18:55:25,628 TRACE AbstractConfiguration stopped 0
>>>>>> Loggers.
>>>>>>>>>>>> 2015-10-12 18:55:25,629 DEBUG Stopped
>>>> org.apache.logging.log4j.core.config.DefaultConfiguration@75c1ada7
>>>>>> OK
>>>>>>>>>>>> 2015-10-12 18:55:25,634 DEBUG Registering MBean
>>>>>>>>>>>> org.apache.logging.log4j2:type=2090228673
>>>>>>>>>>>> 2015-10-12 18:55:25,642 DEBUG Registering MBean
>>>> org.apache.logging.log4j2:type=2090228673,component=StatusLogger
>>>>>>>>>>>> 2015-10-12 18:55:25,647 DEBUG Registering MBean
>>>>> org.apache.logging.log4j2:type=2090228673,component=ContextSelector
>>>>>>>>>>>> 2015-10-12 18:55:25,649 DEBUG Registering MBean
>>>> org.apache.logging.log4j2:type=2090228673,component=Loggers,name=
>>>>>>>>>>>> 2015-10-12 18:55:25,653 DEBUG Registering MBean
>>>> org.apache.logging.log4j2:type=2090228673,component=Loggers,name=,subtype=RingBuffer
>>>>>>>>>>>> 2015-10-12 18:55:25,657 DEBUG Registering MBean
>>>> org.apache.logging.log4j2:type=2090228673,component=Appenders,name=STDOUT
>>>>>>>>>>>> 2015-10-12 18:55:25,659 DEBUG Registering MBean
>>>>> org.apache.logging.log4j2:type=2090228673,component=Appenders,name=File
>>>>>>>>>>>> 2015-10-12 18:55:25,660 DEBUG LoggerContext[name=2090228673,
>>>>>>>>>>>> org.apache.logging.log4j.core.LoggerContext@4347ede7]
>>>> started OK
>>>>>> with
>>>>>>>>>>>> configuration
>>>>>>>>>>>> XmlConfiguration[location=jndi:/localhost/WEB-INF/log4j2.xml].
>>>>>>>>>>>> 2015-10-12 18:55:26,198 DEBUG Starting RollingFileManager
>>>>>>>>>>>> /data/applogs/pigeon/pigeon.data-proxy.log
>>>>>>>>>>>> 2015-10-12 18:55:26,200 DEBUG PluginManager 'FileConverter'
>>>> found
>>>>> 2
>>>>>>>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:26,203 TRACE PatternProcessor.getNextTime
>>>>> returning
>>>>>>>>>>>> 2015/10/13-00:00:00.000, nextFileTime=2015/10/12-00:00:00.000,
>>>>>>>>>>>> prevFileTime=1970/01/01-08:00:00.000,
>>>>>> current=2015/10/12-18:55:26.202,
>>>>>>>>>>>> freq=DAILY
>>>>>>>>>>>> 2015-10-12 18:55:26,204 TRACE PatternProcessor.getNextTime
>>>>> returning
>>>>>>>>>>>> 2015/10/13-00:00:00.000, nextFileTime=2015/10/12-00:00:00.000,
>>>>>>>>>>>> prevFileTime=2015/10/12-00:00:00.000,
>>>>>> current=2015/10/12-18:55:26.203,
>>>>>>>>>>>> freq=DAILY
>>>>>>>>>>>> 2015-10-12 18:55:26,204 DEBUG Starting OutputStreamManager
>>>>>> SYSTEM_ERR
>>>>>>>>>>>> 2015-10-12 18:55:26,207 DEBUG Starting RollingFileManager
>>>>>>>>>>>> /data/applogs/pigeon/pigeon.data-proxy.access.log
>>>>>>>>>>>> 2015-10-12 18:55:26,207 DEBUG PluginManager 'FileConverter'
>>>> found
>>>>> 2
>>>>>>>>>>> plugins
>>>>>>>>>>>> 2015-10-12 18:55:26,208 TRACE PatternProcessor.getNextTime
>>>>> returning
>>>>>>>>>>>> 2015/09/30-00:00:00.000, nextFileTime=2015/09/29-00:00:00.000,
>>>>>>>>>>>> prevFileTime=1970/01/01-08:00:00.000,
>>>>>> current=2015/10/12-18:55:26.208,
>>>>>>>>>>>> freq=DAILY
>>>>>>>>>>>> 2015-10-12 18:55:26,209 TRACE PatternProcessor.getNextTime
>>>>> returning
>>>>>>>>>>>> 2015/09/30-00:00:00.000, nextFileTime=2015/09/29-00:00:00.000,
>>>>>>>>>>>> prevFileTime=2015/09/29-00:00:00.000,
>>>>>> current=2015/10/12-18:55:26.209,
>>>>>>>>>>>> freq=DAILY
>>>>>>>>>>>> 2015-10-12 18:55:26,239 DEBUG Using default SystemClock for
>>>>>> timestamps
>>>>>>>>> 
>>>>>>>>> 
>>>>>>>>> 
>>>>>>>>> --
>>>>>>>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>>>>>>>> Java Persistence with Hibernate, Second Edition
>>>>>>>>> <http://www.manning.com/bauer3/>
>>>>>>>>> JUnit in Action, Second Edition <
>>>> http://www.manning.com/tahchiev/>
>>>>>>>>> Spring Batch in Action <http://www.manning.com/templier/>
>>>>>>>>> Blog: http://garygregory.wordpress.com
>>>>>>>>> Home: http://garygregory.com/
>>>>>>>>> Tweet! http://twitter.com/GaryGregory
>>>> ---------------------------------------------------------------------
>>>>>>>> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
>>>>>>>> For additional commands, e-mail:
>>>> log4j-user-help@logging.apache.org
>>>>>> 
>>>>>> ---------------------------------------------------------------------
>>>>>> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
>>>>>> For additional commands, e-mail: log4j-user-help@logging.apache.org
>>>>> 
>>>>> 
>>>>> --
>>>>> [image: MagineTV]
>>>>> 
>>>>> *Mikael Ståldal*
>>>>> Senior software developer
>>>>> 
>>>>> *Magine TV*
>>>>> mikael.staldal@magine.com
>>>>> Regeringsgatan 25  | 111 53 Stockholm, Sweden  |   www.magine.com
>>>>> 
>>>>> Privileged and/or Confidential Information may be contained in this
>>>>> message. If you are not the addressee indicated in this message
>>>>> (or responsible for delivery of the message to such a person), you may
>>>> not
>>>>> copy or deliver this message to anyone. In such case,
>>>>> you should destroy this message and kindly notify the sender by reply
>>>>> email.
>>>> 
>>>> 
>>>> 
>>>> --
>>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>>> Java Persistence with Hibernate, Second Edition
>>>> <http://www.manning.com/bauer3/>
>>>> JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
>>>> Spring Batch in Action <http://www.manning.com/templier/>
>>>> Blog: http://garygregory.wordpress.com
>>>> Home: http://garygregory.com/
>>>> Tweet! http://twitter.com/GaryGregory
>> 

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