logging-log4j-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Remko Popma <remko.po...@gmail.com>
Subject Re: Bizarre performance in log4j2
Date Mon, 12 Oct 2015 10:35:44 GMT
Can you change the configuration to start with
<Configuration status="trace"

and verify that the correct configuration file (with includeLocation="false") is in use?

I suspect there is something wrong because this change should make a large difference in performance.


Sent from my iPhone

> On 2015/10/12, at 15:22, Strong Su <lovelosew@gmail.com> wrote:
> 
> Hi Remko. Thanks for the reply.
> I changed includeLocation to false and re-run the test.
> But it didn't change better. QPS is still about 5000.
> 
> I found user occupies CPU for about 70% when I run sync log4j1 and sync
> log4j2.
> But when I run async log4j2, it's only about 30% and system occupies for
> about 70%.
> All of them(include sync log4j2 and async log4j2) are under very high load
> average.
> Are these normal numbers?
> 
>> On Sun, Oct 11, 2015 at 7:56 PM, Remko Popma <remko.popma@gmail.com> wrote:
>> 
>> See also http://logging.apache.org/log4j/2.x/manual/async.html#Location
>> and
>> 
>> http://logging.apache.org/log4j/2.x/manual/async.html#Throughput_of_Logging_With_Location_includeLocationtrue
>> 
>> On Sun, Oct 11, 2015 at 1:54 PM, Remko Popma <remko.popma@gmail.com>
>> wrote:
>> 
>>> The problem with the strange performance result is because of the
>>> configuration:
>>> You have includeLocation=true. This will force Log4j to take a snapshot
>> of
>>> the stack and is very slow.
>>> 
>>> Your layouts do not actually use this information, and this explains why
>>> synchronous logging is faster: synchronous logging will _only_ take a
>>> snapshot of the stack when the layout needs it. In your case this is
>> never,
>>> so you get fast performance.
>>> 
>>> The solution is to change your config to
>>> <Root level="info" includeLocation="false">
>>> 
>>> If you test this with async loggers you should see a performance
>>> improvement immediately.
>>> 
>>>> On Sun, Oct 11, 2015 at 12:21 PM, Strong Su <lovelosew@gmail.com> wrote:
>>>> 
>>>> My log4j2 sync configuration is:
>>>> 
>>>> <?xml version="1.0" encoding="UTF-8"?>
>>>> <Configuration>
>>>>    <Appenders>
>>>>        <!-- Async Loggers will auto-flush in batches, so switch off
>>>> immediateFlush. -->
>>>>        <File name="File" fileName="{PATH}/a.log"
>>>> immediateFlush="false" append="false">
>>>>            <PatternLayout pattern="%d %-5p [%c{2}] %m%n"/>
>>>>        </File>
>>>>        <Console name="STDOUT" target="SYSTEM_OUT">
>>>>            <PatternLayout pattern="%d %-5p [%c{2}] %m%n"/>
>>>>        </Console>
>>>>    </Appenders>
>>>> 
>>>>    <Loggers>
>>>>        <Root level="info" includeLocation="true">
>>>>            <AppenderRef ref="File"/>
>>>>            <AppenderRef ref="STDOUT"/>
>>>>        </Root>
>>>>    </Loggers>
>>>> 
>>>> </Configuration>
>>>> 
>>>> And async configuration change <Root> to <AsyncRoot>
>>>> 
>>>> On Sun, Oct 11, 2015 at 10:51 AM, Remko Popma <remko.popma@gmail.com>
>>>> wrote:
>>>> 
>>>>> Can you post your log4j2 configuration?
>>>>> 
>>>>> Sent from my iPhone
>>>>> 
>>>>>> On 2015/10/10, at 21:58, Strong Su <lovelosew@gmail.com> wrote:
>>>>>> 
>>>>>> 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.
>>>>>> When I didn't insert a log in the request function, QPS was about
>>>> 20000.
>>>>>> When I inserted a log4j1 log, QPS was about 10000.
>>>>>> When I inserted a log4j2 sync log, QPS was about 18000.
>>>>>> But when I inserted a log4j2 asycn log, QPS was only about 5000.
>>>>>> 
>>>>>>> On Sat, Oct 10, 2015 at 8:34 PM, Remko Popma <
>> remko.popma@gmail.com>
>>>>> wrote:
>>>>>>> 
>>>>>>> How did you measure the good performance (with sync logging)
and
>> the
>>>> bad
>>>>>>> performance (with async)? What happens exactly when "it turns
>>>> terrible"?
>>>>>>> 
>>>>>>>> On Saturday, 10 October 2015, Strong Su <lovelosew@gmail.com>
>>>> wrote:
>>>>>>>> 
>>>>>>>> Hello everyone,
>>>>>>>> I'm still testing log4j2 on our projects.
>>>>>>>> When using it, I find it has a beautiful performance when
using
>> sync
>>>>>>>> log4j2.
>>>>>>>> But it turns terrible when I add -DLog4jContextSelector or
change
>>>>> <root>
>>>>>>> to
>>>>>>>> <AsyncRoot> in log4j2.xml to use async log4j2.
>>>>>>>> I don't even have a clue on explaining this.What could cause
this
>>>>> bizarre
>>>>>>>> problem?
>>>>>>>> 
>>>>>>>> Thank you.
>>>>>>>> Best regards,
>>>>>>>> Dylan Su
>>>>>>> 
>>>>> 
>>>>> ---------------------------------------------------------------------
>>>>> 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


Mime
View raw message