I will try taking a look when I get home from work tonight.
Ceki reported some strange numbers about Log4j 1 outperforming Log4j2 before, and when we
showed results from 3 or 4 environments that disproved his claims, he never really explained
how that happened.
Not sure if there's some issue with his test setup... I would definitely double check his
numbers.
Sent from my iPhone
> On Feb 9, 2017, at 14:12, Apache <ralph.goers@dslextreme.com> wrote:
>
> Logback 1.2 has been released. I just ran our performance benchmarks against it and I
am mystified. Logback 1.2 is coming out almost 4 times slower than 1.1.10. Can someone please
verify my results?
>
> I am running them with
>
> java -jar target/benchmarks.jar ".*FileAppenderBenchmark.*" -f 1 -wi 10 -i 10 -t 4 -tu
ms
>
> This is on my MacBook Pro (mid-2015) with a 2.8 GHz Intel Core i7 and a fast SSD.
>
> Benchmark Mode Samples Score Error
Units
> o.a.l.l.p.j.FileAppenderBenchmark.julFile thrpt 10 94.052 ± 13.645
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j1File thrpt 10 838.130 ± 11.205
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2File thrpt 10 1844.284 ± 72.803
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2MMF thrpt 10 2041.727 ± 1260.868
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2RAF thrpt 10 1879.691 ± 93.162
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.logbackFile thrpt 10 287.678 ± 8.516
ops/ms
>
>
> This is on a Mac Pro (mid-2013) with a 3.5 GHz Intel 6 Core Xeon E5 with an external
USB SSD.
>
> Benchmark Mode Samples Score Error
Units
> o.a.l.l.p.j.FileAppenderBenchmark.julFile thrpt 10 67.616 ± 8.256
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j1File thrpt 10 607.507 ± 87.307
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2File thrpt 10 668.316 ± 124.457
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2MMF thrpt 10 3174.031 ± 149.277
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2RAF thrpt 10 839.811 ± 154.662
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.logbackFile thrpt 10 175.482 ± 0.869
ops/ms
>
> This is also on the same Map Pro (mid-2013) but using the faster internal SSD.
>
> Benchmark Mode Samples Score Error
Units
> o.a.l.l.p.j.FileAppenderBenchmark.julFile thrpt 10 75.435 ± 0.287
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j1File thrpt 10 735.162 ± 5.182
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2File thrpt 10 1346.217 ± 13.955
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2MMF thrpt 10 2439.903 ± 355.553
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2RAF thrpt 10 1507.775 ± 9.600
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.logbackFile thrpt 10 184.796 ± 2.052
ops/ms
>
> Finally, this is on my old MacBook Pro (Late-2011) 2.5GHz Intel Core i5 with an internal
hard drive.
>
> Benchmark Mode Samples Score Error
Units
> o.a.l.l.p.j.FileAppenderBenchmark.julFile thrpt 10 39.181 ± 3.315
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j1File thrpt 10 485.160 ± 98.892
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2File thrpt 10 551.578 ± 120.902
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2MMF thrpt 10 1720.083 ± 1113.734
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2RAF thrpt 10 561.398 ± 226.339
ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.logbackFile thrpt 10 161.530 ± 4.585
ops/ms
>
> The news page at Logback says that it has major performance improvements but these numbers
are 3-4 times slower than what I got with 1.1.10.
>
> Ralph
>
>
>
>
>
>
>
>
>
>> On Feb 8, 2017, at 10:31 AM, Apache <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> 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> 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> 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> 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>
wrote:
>>>>>>> Ceki has updated his numbers to include those reported on the
mailing list. 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.
>>>>>>>
>>>>>>> Ralph
>>>>>>>
>>>>>>>> On Feb 6, 2017, at 9:33 AM, Apache <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>
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>
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>
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>
wrote:
>>>>>>>>>>>> You should run the code at 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> 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> 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> wrote:
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> Ceki finally fixed some of the
performance problems in the FileAppender. See https://logback.qos.ch/news.html and 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>
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> --
>>>>>>>>> Matt Sicker <boards@gmail.com>
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> --
>>>>>> Matt Sicker <boards@gmail.com>
>>>>>
>>>>>
>>>>>
>>>>> --
>>>>> Matt Sicker <boards@gmail.com>
>>>>
>>>
>>
>
|