logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache <ralph.go...@dslextreme.com>
Subject Re: Logback performance improvements
Date Thu, 09 Feb 2017 15:39:00 GMT
It is there now.

Ralph

> On Feb 9, 2017, at 7:46 AM, Remko Popma <remko.popma@gmail.com> wrote:
> 
> can you push the correct config?
> 
> On Thu, Feb 9, 2017 at 11:03 PM, Apache <ralph.goers@dslextreme.com <mailto:ralph.goers@dslextreme.com>>
wrote:
> After modifying the configuration the new results on my laptop are:
> 
> Benchmark                                         Mode  Samples     Score      Error
  Units
> o.a.l.l.p.j.FileAppenderBenchmark.julFile        thrpt       10    92.580 ±    3.698
 ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j1File     thrpt       10   828.707 ±   55.006
 ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2File     thrpt       10  1647.230 ±  125.682
 ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2MMF      thrpt       10  1465.002 ± 1284.943
 ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2RAF      thrpt       10  1765.340 ±  149.707
 ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.logbackFile    thrpt       10  1192.594 ±   57.777
 ops/ms
> 
> I will try the other machines later and post those results.
> 
> Ralph
> 
> 
>> On Feb 9, 2017, at 5:22 AM, Apache <ralph.goers@dslextreme.com <mailto:ralph.goers@dslextreme.com>>
wrote:
>> 
>> Ceki replied on twitter that the immediateFlush option is now a parameter of the
appended, not the encoder, so it looks like the confit needs to be changed and the test rerun.
>> 
>> Ralph
>> 
>> On Feb 9, 2017, at 3:08 AM, Remko Popma <remko.popma@gmail.com <mailto:remko.popma@gmail.com>>
wrote:
>> 
>>> FYI, The write and flush methods in BufferedOutputStream are also synchronized,
so we won't be able to do away with synchronization completely. 
>>> 
>>> In OutputStreamManager we synchronize multiple methods but these are nested calls.
I thought reentrant synchronization had negligible overhead but I haven't measured this myself.

>>> 
>>> 
>>> Sent from my iPhone
>>> 
>>> On Feb 9, 2017, at 2:31, Apache <ralph.goers@dslextreme.com <mailto:ralph.goers@dslextreme.com>>
wrote:
>>> 
>>>> I’m pretty sure the problem we have is that a) we are synchronizing many
methods and b) we are synchronizing more than just the write. Unfortunately, I can’t figure
out how to reduce that based on how dispersed the code has gotten.
>>>> 
>>>> Ralph
>>>> 
>>>>> On Feb 8, 2017, at 10:14 AM, Apache <ralph.goers@dslextreme.com <mailto:ralph.goers@dslextreme.com>>
wrote:
>>>>> 
>>>>> I tried to modify FileManager to just use a BufferedOutputStream but
discovered I couldn’t as the layouts now require the ByteBuffer. 
>>>>> 
>>>>> Ralph
>>>>> 
>>>>>> On Feb 8, 2017, at 12:14 AM, Apache <ralph.goers@dslextreme.com
<mailto:ralph.goers@dslextreme.com>> wrote:
>>>>>> 
>>>>>> The append method isn’t synchronized but the writeBytes method
acquires a lock. His code is actually a lot simpler than ours in that it just uses a BufferedOutputStream
and he only obtains the lock when he is writing to it.
>>>>>> 
>>>>>> Ralph
>>>>>> 
>>>>>>> On Feb 6, 2017, at 5:23 PM, Matt Sicker <boards@gmail.com
<mailto:boards@gmail.com>> wrote:
>>>>>>> 
>>>>>>> I'm not sure if I'm looking in the right place, but a major difference
now between Logback's appenders and Log4j's is that Logback isn't synchronized on the append
method.
>>>>>>> 
>>>>>>> On 6 February 2017 at 18:18, Matt Sicker <boards@gmail.com
<mailto:boards@gmail.com>> wrote:
>>>>>>> Is this something we can improve performance on by implementing
a file appender based on FileChannel or AsynchronousFileChannel instead of OutputStream?
>>>>>>> 
>>>>>>> On 6 February 2017 at 17:50, Apache <ralph.goers@dslextreme.com
<mailto:ralph.goers@dslextreme.com>> wrote:
>>>>>>> Ceki has updated his numbers to include those reported on the
mailing list. https://docs.google.com/spreadsheets/d/1cpb5D7qnyye4W0RTlHUnXedYK98catNZytYIu5D91m0/edit#gid=0
<https://docs.google.com/spreadsheets/d/1cpb5D7qnyye4W0RTlHUnXedYK98catNZytYIu5D91m0/edit#gid=0>
>>>>>>> 
>>>>>>> I haven’t run the tests with Logback 1.2-SNAPSHOT but my numbers
for my two MacBooks are at https://docs.google.com/spreadsheets/d/1L67IhmUVvyLBWtC6iq0TMj-j0vrbKsUKWuZV0Nlqisk/edit?usp=sharing
<https://docs.google.com/spreadsheets/d/1L67IhmUVvyLBWtC6iq0TMj-j0vrbKsUKWuZV0Nlqisk/edit?usp=sharing>.

>>>>>>> 
>>>>>>> Ralph
>>>>>>> 
>>>>>>>> On Feb 6, 2017, at 9:33 AM, Apache <ralph.goers@dslextreme.com
<mailto:ralph.goers@dslextreme.com>> wrote:
>>>>>>>> 
>>>>>>>> Yes, that is still the standard approach most people use
and is the only way to provide a head-to-head comparison against the logging frameworks.
>>>>>>>> 
>>>>>>>> Ralph
>>>>>>>> 
>>>>>>>>> On Feb 6, 2017, at 8:02 AM, Matt Sicker <boards@gmail.com
<mailto:boards@gmail.com>> wrote:
>>>>>>>>> 
>>>>>>>>> This is all in a synchronous appender, right? Either
way, that's rather interesting.
>>>>>>>>> 
>>>>>>>>> On 6 February 2017 at 07:54, Apache <ralph.goers@dslextreme.com
<mailto:ralph.goers@dslextreme.com>> wrote:
>>>>>>>>> Someone posted numbers on the Logback user’s list that
match mine.  It shows Logback 1.1.9 was pretty terrible, 1.1.10 is somewhat better and 1.2-SNAPSHOT
is on par or slightly better than Log4j 2.
>>>>>>>>> 
>>>>>>>>> Ralph
>>>>>>>>> 
>>>>>>>>>> On Feb 5, 2017, at 3:25 PM, Matt Sicker <boards@gmail.com
<mailto:boards@gmail.com>> wrote:
>>>>>>>>>> 
>>>>>>>>>> I think we need some comparisons on the log4j side:
file appender with 256k buffer size, random access file appender with 256k buffer size (which
appears to be the default), and memory mapped file appender. It'd be cool to see how these
compose with async logging enabled in both log4j and logback.
>>>>>>>>>> 
>>>>>>>>>> On 5 February 2017 at 16:06, Apache <ralph.goers@dslextreme.com
<mailto:ralph.goers@dslextreme.com>> wrote:
>>>>>>>>>> You should run the code at https://github.com/ceki/logback-perf
<https://github.com/ceki/logback-perf> to compare your results to Ceki’s.  You also
should capture the cpubenchmark speed of your processor and get the speed of your hard drive.
I used Blackmagic speed test on my Mac. I am capturing my results in a Google spreadsheet.
I will post the like once I have it.
>>>>>>>>>> 
>>>>>>>>>> Ralph
>>>>>>>>>> 
>>>>>>>>>>> On Feb 5, 2017, at 1:48 PM, Gary Gregory <garydgregory@gmail.com
<mailto:garydgregory@gmail.com>> wrote:
>>>>>>>>>>> 
>>>>>>>>>>> If you want, I can run tests on Windows once
the build works on Windows again.
>>>>>>>>>>> 
>>>>>>>>>>> Let me know what args/command line...
>>>>>>>>>>> 
>>>>>>>>>>> Gary
>>>>>>>>>>> 
>>>>>>>>>>> On Feb 5, 2017 11:58 AM, "Apache" <ralph.goers@dslextreme.com
<mailto:ralph.goers@dslextreme.com>> wrote:
>>>>>>>>>>> I guess my MacBook Pro must fit in the Slow CPU/Fast
Hard drive category. With Logback 1.10 and -t 4  now get
>>>>>>>>>>> 
>>>>>>>>>>> Benchmark                                   
     Mode  Samples        Score       Error  Units
>>>>>>>>>>> o.a.l.l.p.j.FileAppenderBenchmark.julFile   
    thrpt       20    98187.673 ±  4935.712  ops/s
>>>>>>>>>>> o.a.l.l.p.j.FileAppenderBenchmark.log4j1File
    thrpt       20   842374.496 ±  6762.712  ops/s
>>>>>>>>>>> o.a.l.l.p.j.FileAppenderBenchmark.log4j2File
    thrpt       20  1853062.583 ± 67032.225  ops/s
>>>>>>>>>>> o.a.l.l.p.j.FileAppenderBenchmark.log4j2RAF 
    thrpt       20  2036011.226 ± 53208.281  ops/s
>>>>>>>>>>> o.a.l.l.p.j.FileAppenderBenchmark.logbackFile
   thrpt       20   999667.438 ± 12074.003  ops/s
>>>>>>>>>>> 
>>>>>>>>>>> I’ll have to try this on one my VMs at work.
We don’t run anything directly on bare metal any more.
>>>>>>>>>>> 
>>>>>>>>>>> Ralph
>>>>>>>>>>> 
>>>>>>>>>>>> On Feb 5, 2017, at 9:40 AM, Apache <ralph.goers@dslextreme.com
<mailto:ralph.goers@dslextreme.com>> wrote:
>>>>>>>>>>>> 
>>>>>>>>>>>> Ceki finally fixed some of the performance
problems in the FileAppender. See https://logback.qos.ch/news.html <https://logback.qos.ch/news.html>
and https://docs.google.com/spreadsheets/d/1cpb5D7qnyye4W0RTlHUnXedYK98catNZytYIu5D91m0/edit#gid=0
<https://docs.google.com/spreadsheets/d/1cpb5D7qnyye4W0RTlHUnXedYK98catNZytYIu5D91m0/edit#gid=0>.
I suspect we have a few optimizations we can make.
>>>>>>>>>>>> 
>>>>>>>>>>>> Ralph
>>>>>>>>>>> 
>>>>>>>>>> 
>>>>>>>>>> 
>>>>>>>>>> 
>>>>>>>>>> 
>>>>>>>>>> -- 
>>>>>>>>>> Matt Sicker <boards@gmail.com <mailto:boards@gmail.com>>
>>>>>>>>> 
>>>>>>>>> 
>>>>>>>>> 
>>>>>>>>> 
>>>>>>>>> -- 
>>>>>>>>> Matt Sicker <boards@gmail.com <mailto:boards@gmail.com>>
>>>>>>>> 
>>>>>>> 
>>>>>>> 
>>>>>>> 
>>>>>>> 
>>>>>>> -- 
>>>>>>> Matt Sicker <boards@gmail.com <mailto:boards@gmail.com>>
>>>>>>> 
>>>>>>> 
>>>>>>> 
>>>>>>> -- 
>>>>>>> Matt Sicker <boards@gmail.com <mailto:boards@gmail.com>>
>>>>>> 
>>>>> 
>>>> 
> 
> 


Mime
View raw message