You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by Remko Popma <re...@gmail.com> on 2016/04/12 18:30:09 UTC
FileAppender synchronous logging performance
I wanted to share the results of some initial performance tests.
This is from the log4j-perf FileAppenderBenchmark, starting with 1 thread,
ending at 64 threads. It compares Logback to Log4j 1.2 to Log4j 2.
Point of interest for me is "direct enc": use the garbage-free
Layout.encode(LogEvent, ByteBufferDestination), vs. "allocate": create
byte[] and Strings by calling Layout.toByteArray().
Looks like at the moment garbage-free is better with a single thread and
allocating is better with more threads.
This is because the current implementation locks on the OutputStreamManager
while writing into the shared buffer.
I'm very happy with this initial result.
We can probably improve on this with a threadlocal byte buffer so we only
need to lock when copying that threadlocal buffer into the shared buffer.
What is also interesting is how much better Log4j 2 is compared to Logback
and Log4j, especially with more than one thread.
Command to run the tests:
java -Dlog4j2.enable.direct.encoders=true -jar
benchmarks-LOG4J2-1343-20160411.jar ".*FileAppender.*" -f 1 -wi 10 -i 20
-bm thrpt -tu s -t 1
(increase threads with -t 2, -t 4 etc, use
log4j2.enable.direct.encoders=false to use Layout.toByteArray())
Re: FileAppender synchronous logging performance
Posted by Remko Popma <re...@gmail.com>.
Resending graphs with markers to rely less on colors.
On Linux 2.6, using a thread-local buffer (with a final synchronized copy)
is slightly better than doing all of the encoding in a synchronized block,
but the opposite is true on Win 7. Also, the non-garbage free
String.getBytes() mechanism had higher throughput in my multithreaded tests.
Graphs source and raw data are in the attached spreadsheet.
I will work on a response time (latency) test next.
On Thu, Apr 14, 2016 at 8:09 AM, Remko Popma <re...@gmail.com> wrote:
> Sure. By the way, the previous email had an attachment with the
> spreadsheet containing the graphs. Can you see if you can open that?
>
> I can see what I can do but it'll take a day.
>
> Sent from my iPhone
>
> On 2016/04/14, at 3:31, Ralph Goers <ra...@dslextreme.com> wrote:
>
> I’m wondering if you could do me a favor. I am color blind and have a hard
> time differentiating which graph is which. Can you also incorporate dots
> or dashes into the lines so I can tell the difference?
>
> Ralph
>
> On Apr 13, 2016, at 8:31 AM, Remko Popma <re...@gmail.com> wrote:
>
> On Linux 2.6, using a thread-local buffer (with a final synchronized copy)
> is slightly better than doing all of the encoding in a synchronized block,
> but the opposite is true on Win 7. Also, the non-garbage free
> String.getBytes() mechanism had higher throughput in my multithreaded tests.
>
> More data is in the attached spreadsheet.
>
> I will work on a response time (latency) test next.
>
> <SyncThroughputLinux2.6.png>
> <SyncThroughputWin7.png>
>
>
> On Wed, Apr 13, 2016 at 7:59 AM, Remko Popma <re...@gmail.com>
> wrote:
>
>> Let me optimize a bit with the ThreadLocal idea before adding it to the
>> performance page.
>>
>> Sent from my iPhone
>>
>> > On 2016/04/13, at 3:27, Ralph Goers <ra...@dslextreme.com> wrote:
>> >
>> > Something you could add to the performance page on the site perhaps?
>> >
>> > If I am not mistaken Logback still has code that doesn’t use
>> UnsynchronizedAppenderBase so it would have more locking contention. But I
>> don’t know if this test is one of them. I would agree that a ThreadLocal
>> byte buffer might make a difference.
>> >
>> > Ralph
>> >
>> >> On Apr 12, 2016, at 9:30 AM, Remko Popma <re...@gmail.com>
>> wrote:
>> >>
>> >> I wanted to share the results of some initial performance tests.
>> >>
>> >> This is from the log4j-perf FileAppenderBenchmark, starting with 1
>> thread, ending at 64 threads. It compares Logback to Log4j 1.2 to Log4j 2.
>> >>
>> >> Point of interest for me is "direct enc": use the garbage-free
>> Layout.encode(LogEvent, ByteBufferDestination), vs. "allocate": create
>> byte[] and Strings by calling Layout.toByteArray().
>> >>
>> >> <FileAppenderLinux2.6.png>
>> >>
>> >> Looks like at the moment garbage-free is better with a single thread
>> and allocating is better with more threads.
>> >>
>> >> This is because the current implementation locks on the
>> OutputStreamManager while writing into the shared buffer.
>> >>
>> >> I'm very happy with this initial result.
>> >> We can probably improve on this with a threadlocal byte buffer so we
>> only need to lock when copying that threadlocal buffer into the shared
>> buffer.
>> >>
>> >> What is also interesting is how much better Log4j 2 is compared to
>> Logback and Log4j, especially with more than one thread.
>> >>
>> >> Command to run the tests:
>> >> java -Dlog4j2.enable.direct.encoders=true -jar
>> benchmarks-LOG4J2-1343-20160411.jar ".*FileAppender.*" -f 1 -wi 10 -i 20
>> -bm thrpt -tu s -t 1
>> >>
>> >> (increase threads with -t 2, -t 4 etc, use
>> log4j2.enable.direct.encoders=false to use Layout.toByteArray())
>> >
>> >
>> >
>> > ---------------------------------------------------------------------
>> > To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>> > For additional commands, e-mail: log4j-dev-help@logging.apache.org
>> >
>>
>
> <FileAppender20160413.xlsx>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>
>
>
Re: FileAppender synchronous logging performance
Posted by Remko Popma <re...@gmail.com>.
Sure. By the way, the previous email had an attachment with the spreadsheet containing the graphs. Can you see if you can open that?
I can see what I can do but it'll take a day.
Sent from my iPhone
> On 2016/04/14, at 3:31, Ralph Goers <ra...@dslextreme.com> wrote:
>
> I’m wondering if you could do me a favor. I am color blind and have a hard time differentiating which graph is which. Can you also incorporate dots or dashes into the lines so I can tell the difference?
>
> Ralph
>
>> On Apr 13, 2016, at 8:31 AM, Remko Popma <re...@gmail.com> wrote:
>>
>> On Linux 2.6, using a thread-local buffer (with a final synchronized copy) is slightly better than doing all of the encoding in a synchronized block, but the opposite is true on Win 7. Also, the non-garbage free String.getBytes() mechanism had higher throughput in my multithreaded tests.
>>
>> More data is in the attached spreadsheet.
>>
>> I will work on a response time (latency) test next.
>>
>> <SyncThroughputLinux2.6.png>
>> <SyncThroughputWin7.png>
>>
>>
>>> On Wed, Apr 13, 2016 at 7:59 AM, Remko Popma <re...@gmail.com> wrote:
>>> Let me optimize a bit with the ThreadLocal idea before adding it to the performance page.
>>>
>>> Sent from my iPhone
>>>
>>> > On 2016/04/13, at 3:27, Ralph Goers <ra...@dslextreme.com> wrote:
>>> >
>>> > Something you could add to the performance page on the site perhaps?
>>> >
>>> > If I am not mistaken Logback still has code that doesn’t use UnsynchronizedAppenderBase so it would have more locking contention. But I don’t know if this test is one of them. I would agree that a ThreadLocal byte buffer might make a difference.
>>> >
>>> > Ralph
>>> >
>>> >> On Apr 12, 2016, at 9:30 AM, Remko Popma <re...@gmail.com> wrote:
>>> >>
>>> >> I wanted to share the results of some initial performance tests.
>>> >>
>>> >> This is from the log4j-perf FileAppenderBenchmark, starting with 1 thread, ending at 64 threads. It compares Logback to Log4j 1.2 to Log4j 2.
>>> >>
>>> >> Point of interest for me is "direct enc": use the garbage-free Layout.encode(LogEvent, ByteBufferDestination), vs. "allocate": create byte[] and Strings by calling Layout.toByteArray().
>>> >>
>>> >> <FileAppenderLinux2.6.png>
>>> >>
>>> >> Looks like at the moment garbage-free is better with a single thread and allocating is better with more threads.
>>> >>
>>> >> This is because the current implementation locks on the OutputStreamManager while writing into the shared buffer.
>>> >>
>>> >> I'm very happy with this initial result.
>>> >> We can probably improve on this with a threadlocal byte buffer so we only need to lock when copying that threadlocal buffer into the shared buffer.
>>> >>
>>> >> What is also interesting is how much better Log4j 2 is compared to Logback and Log4j, especially with more than one thread.
>>> >>
>>> >> Command to run the tests:
>>> >> java -Dlog4j2.enable.direct.encoders=true -jar benchmarks-LOG4J2-1343-20160411.jar ".*FileAppender.*" -f 1 -wi 10 -i 20 -bm thrpt -tu s -t 1
>>> >>
>>> >> (increase threads with -t 2, -t 4 etc, use log4j2.enable.direct.encoders=false to use Layout.toByteArray())
>>> >
>>> >
>>> >
>>> > ---------------------------------------------------------------------
>>> > To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>>> > For additional commands, e-mail: log4j-dev-help@logging.apache.org
>>> >
>>
>> <FileAppender20160413.xlsx>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>
Re: FileAppender synchronous logging performance
Posted by Ralph Goers <ra...@dslextreme.com>.
I’m wondering if you could do me a favor. I am color blind and have a hard time differentiating which graph is which. Can you also incorporate dots or dashes into the lines so I can tell the difference?
Ralph
> On Apr 13, 2016, at 8:31 AM, Remko Popma <re...@gmail.com> wrote:
>
> On Linux 2.6, using a thread-local buffer (with a final synchronized copy) is slightly better than doing all of the encoding in a synchronized block, but the opposite is true on Win 7. Also, the non-garbage free String.getBytes() mechanism had higher throughput in my multithreaded tests.
>
> More data is in the attached spreadsheet.
>
> I will work on a response time (latency) test next.
>
> <SyncThroughputLinux2.6.png>
> <SyncThroughputWin7.png>
>
>
> On Wed, Apr 13, 2016 at 7:59 AM, Remko Popma <remko.popma@gmail.com <ma...@gmail.com>> wrote:
> Let me optimize a bit with the ThreadLocal idea before adding it to the performance page.
>
> Sent from my iPhone
>
> > On 2016/04/13, at 3:27, Ralph Goers <ralph.goers@dslextreme.com <ma...@dslextreme.com>> wrote:
> >
> > Something you could add to the performance page on the site perhaps?
> >
> > If I am not mistaken Logback still has code that doesn’t use UnsynchronizedAppenderBase so it would have more locking contention. But I don’t know if this test is one of them. I would agree that a ThreadLocal byte buffer might make a difference.
> >
> > Ralph
> >
> >> On Apr 12, 2016, at 9:30 AM, Remko Popma <remko.popma@gmail.com <ma...@gmail.com>> wrote:
> >>
> >> I wanted to share the results of some initial performance tests.
> >>
> >> This is from the log4j-perf FileAppenderBenchmark, starting with 1 thread, ending at 64 threads. It compares Logback to Log4j 1.2 to Log4j 2.
> >>
> >> Point of interest for me is "direct enc": use the garbage-free Layout.encode(LogEvent, ByteBufferDestination), vs. "allocate": create byte[] and Strings by calling Layout.toByteArray().
> >>
> >> <FileAppenderLinux2.6.png>
> >>
> >> Looks like at the moment garbage-free is better with a single thread and allocating is better with more threads.
> >>
> >> This is because the current implementation locks on the OutputStreamManager while writing into the shared buffer.
> >>
> >> I'm very happy with this initial result.
> >> We can probably improve on this with a threadlocal byte buffer so we only need to lock when copying that threadlocal buffer into the shared buffer.
> >>
> >> What is also interesting is how much better Log4j 2 is compared to Logback and Log4j, especially with more than one thread.
> >>
> >> Command to run the tests:
> >> java -Dlog4j2.enable.direct.encoders=true -jar benchmarks-LOG4J2-1343-20160411.jar ".*FileAppender.*" -f 1 -wi 10 -i 20 -bm thrpt -tu s -t 1
> >>
> >> (increase threads with -t 2, -t 4 etc, use log4j2.enable.direct.encoders=false to use Layout.toByteArray())
> >
> >
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org <ma...@logging.apache.org>
> > For additional commands, e-mail: log4j-dev-help@logging.apache.org <ma...@logging.apache.org>
> >
>
> <FileAppender20160413.xlsx>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org <ma...@logging.apache.org>
> For additional commands, e-mail: log4j-dev-help@logging.apache.org <ma...@logging.apache.org>
Re: FileAppender synchronous logging performance
Posted by Remko Popma <re...@gmail.com>.
On Linux 2.6, using a thread-local buffer (with a final synchronized copy)
is slightly better than doing all of the encoding in a synchronized block,
but the opposite is true on Win 7. Also, the non-garbage free
String.getBytes() mechanism had higher throughput in my multithreaded tests.
More data is in the attached spreadsheet.
I will work on a response time (latency) test next.
On Wed, Apr 13, 2016 at 7:59 AM, Remko Popma <re...@gmail.com> wrote:
> Let me optimize a bit with the ThreadLocal idea before adding it to the
> performance page.
>
> Sent from my iPhone
>
> > On 2016/04/13, at 3:27, Ralph Goers <ra...@dslextreme.com> wrote:
> >
> > Something you could add to the performance page on the site perhaps?
> >
> > If I am not mistaken Logback still has code that doesn’t use
> UnsynchronizedAppenderBase so it would have more locking contention. But I
> don’t know if this test is one of them. I would agree that a ThreadLocal
> byte buffer might make a difference.
> >
> > Ralph
> >
> >> On Apr 12, 2016, at 9:30 AM, Remko Popma <re...@gmail.com> wrote:
> >>
> >> I wanted to share the results of some initial performance tests.
> >>
> >> This is from the log4j-perf FileAppenderBenchmark, starting with 1
> thread, ending at 64 threads. It compares Logback to Log4j 1.2 to Log4j 2.
> >>
> >> Point of interest for me is "direct enc": use the garbage-free
> Layout.encode(LogEvent, ByteBufferDestination), vs. "allocate": create
> byte[] and Strings by calling Layout.toByteArray().
> >>
> >> <FileAppenderLinux2.6.png>
> >>
> >> Looks like at the moment garbage-free is better with a single thread
> and allocating is better with more threads.
> >>
> >> This is because the current implementation locks on the
> OutputStreamManager while writing into the shared buffer.
> >>
> >> I'm very happy with this initial result.
> >> We can probably improve on this with a threadlocal byte buffer so we
> only need to lock when copying that threadlocal buffer into the shared
> buffer.
> >>
> >> What is also interesting is how much better Log4j 2 is compared to
> Logback and Log4j, especially with more than one thread.
> >>
> >> Command to run the tests:
> >> java -Dlog4j2.enable.direct.encoders=true -jar
> benchmarks-LOG4J2-1343-20160411.jar ".*FileAppender.*" -f 1 -wi 10 -i 20
> -bm thrpt -tu s -t 1
> >>
> >> (increase threads with -t 2, -t 4 etc, use
> log4j2.enable.direct.encoders=false to use Layout.toByteArray())
> >
> >
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> > For additional commands, e-mail: log4j-dev-help@logging.apache.org
> >
>
Re: FileAppender synchronous logging performance
Posted by Remko Popma <re...@gmail.com>.
Let me optimize a bit with the ThreadLocal idea before adding it to the performance page.
Sent from my iPhone
> On 2016/04/13, at 3:27, Ralph Goers <ra...@dslextreme.com> wrote:
>
> Something you could add to the performance page on the site perhaps?
>
> If I am not mistaken Logback still has code that doesn’t use UnsynchronizedAppenderBase so it would have more locking contention. But I don’t know if this test is one of them. I would agree that a ThreadLocal byte buffer might make a difference.
>
> Ralph
>
>> On Apr 12, 2016, at 9:30 AM, Remko Popma <re...@gmail.com> wrote:
>>
>> I wanted to share the results of some initial performance tests.
>>
>> This is from the log4j-perf FileAppenderBenchmark, starting with 1 thread, ending at 64 threads. It compares Logback to Log4j 1.2 to Log4j 2.
>>
>> Point of interest for me is "direct enc": use the garbage-free Layout.encode(LogEvent, ByteBufferDestination), vs. "allocate": create byte[] and Strings by calling Layout.toByteArray().
>>
>> <FileAppenderLinux2.6.png>
>>
>> Looks like at the moment garbage-free is better with a single thread and allocating is better with more threads.
>>
>> This is because the current implementation locks on the OutputStreamManager while writing into the shared buffer.
>>
>> I'm very happy with this initial result.
>> We can probably improve on this with a threadlocal byte buffer so we only need to lock when copying that threadlocal buffer into the shared buffer.
>>
>> What is also interesting is how much better Log4j 2 is compared to Logback and Log4j, especially with more than one thread.
>>
>> Command to run the tests:
>> java -Dlog4j2.enable.direct.encoders=true -jar benchmarks-LOG4J2-1343-20160411.jar ".*FileAppender.*" -f 1 -wi 10 -i 20 -bm thrpt -tu s -t 1
>>
>> (increase threads with -t 2, -t 4 etc, use log4j2.enable.direct.encoders=false to use Layout.toByteArray())
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org
Re: FileAppender synchronous logging performance
Posted by Remko Popma <re...@gmail.com>.
Based on the docs in the JMH samples throughput is the total for all
threads. (
http://hg.openjdk.java.net/code-tools/jmh/file/39ed8b3c11ce/jmh-samples/src/main/java/org/openjdk/jmh/samples/JMHSample_02_BenchmarkModes.java
)
On Wednesday, 13 April 2016, Remko Popma <re...@gmail.com> wrote:
> Robin, this is a JMH benchmark. I _think_ it simply counts the number of
> times the test code (logger.log(...)) was invoked for all threads together.
> Need to double check.
>
> In which case this would be a good illustration of Amdahl's law.
> https://en.wikipedia.org/wiki/Amdahl%27s_law
> (Conclusion: Write single-threaded apps or use the lock free async
> Loggers. )
>
>
> Sent from my iPhone
>
> On 2016/04/13, at 5:32, Robin Coe <rcoe.javadev@gmail.com
> <javascript:_e(%7B%7D,'cvml','rcoe.javadev@gmail.com');>> wrote:
>
> Is that total msg/s across all threads or per thread? I expect it's per
> thread but wanted to be sure, as the single threaded performance would make
> it seem that you shouldn't run multithreaded.
>
> On Tue, Apr 12, 2016 at 2:27 PM, Ralph Goers <ralph.goers@dslextreme.com
> <javascript:_e(%7B%7D,'cvml','ralph.goers@dslextreme.com');>> wrote:
>
>> Something you could add to the performance page on the site perhaps?
>>
>> If I am not mistaken Logback still has code that doesn’t use
>> UnsynchronizedAppenderBase so it would have more locking contention. But I
>> don’t know if this test is one of them. I would agree that a ThreadLocal
>> byte buffer might make a difference.
>>
>> Ralph
>>
>> > On Apr 12, 2016, at 9:30 AM, Remko Popma <remko.popma@gmail.com
>> <javascript:_e(%7B%7D,'cvml','remko.popma@gmail.com');>> wrote:
>> >
>> > I wanted to share the results of some initial performance tests.
>> >
>> > This is from the log4j-perf FileAppenderBenchmark, starting with 1
>> thread, ending at 64 threads. It compares Logback to Log4j 1.2 to Log4j 2.
>> >
>> > Point of interest for me is "direct enc": use the garbage-free
>> Layout.encode(LogEvent, ByteBufferDestination), vs. "allocate": create
>> byte[] and Strings by calling Layout.toByteArray().
>> >
>> > <FileAppenderLinux2.6.png>
>> >
>> > Looks like at the moment garbage-free is better with a single thread
>> and allocating is better with more threads.
>> >
>> > This is because the current implementation locks on the
>> OutputStreamManager while writing into the shared buffer.
>> >
>> > I'm very happy with this initial result.
>> > We can probably improve on this with a threadlocal byte buffer so we
>> only need to lock when copying that threadlocal buffer into the shared
>> buffer.
>> >
>> > What is also interesting is how much better Log4j 2 is compared to
>> Logback and Log4j, especially with more than one thread.
>> >
>> > Command to run the tests:
>> > java -Dlog4j2.enable.direct.encoders=true -jar
>> benchmarks-LOG4J2-1343-20160411.jar ".*FileAppender.*" -f 1 -wi 10 -i 20
>> -bm thrpt -tu s -t 1
>> >
>> > (increase threads with -t 2, -t 4 etc, use
>> log4j2.enable.direct.encoders=false to use Layout.toByteArray())
>> >
>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>> <javascript:_e(%7B%7D,'cvml','log4j-dev-unsubscribe@logging.apache.org');>
>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>> <javascript:_e(%7B%7D,'cvml','log4j-dev-help@logging.apache.org');>
>>
>>
>
Re: FileAppender synchronous logging performance
Posted by Remko Popma <re...@gmail.com>.
Robin, this is a JMH benchmark. I _think_ it simply counts the number of times the test code (logger.log(...)) was invoked for all threads together. Need to double check.
In which case this would be a good illustration of Amdahl's law. https://en.wikipedia.org/wiki/Amdahl%27s_law
(Conclusion: Write single-threaded apps or use the lock free async Loggers. )
Sent from my iPhone
> On 2016/04/13, at 5:32, Robin Coe <rc...@gmail.com> wrote:
>
> Is that total msg/s across all threads or per thread? I expect it's per thread but wanted to be sure, as the single threaded performance would make it seem that you shouldn't run multithreaded.
>
>> On Tue, Apr 12, 2016 at 2:27 PM, Ralph Goers <ra...@dslextreme.com> wrote:
>> Something you could add to the performance page on the site perhaps?
>>
>> If I am not mistaken Logback still has code that doesn’t use UnsynchronizedAppenderBase so it would have more locking contention. But I don’t know if this test is one of them. I would agree that a ThreadLocal byte buffer might make a difference.
>>
>> Ralph
>>
>> > On Apr 12, 2016, at 9:30 AM, Remko Popma <re...@gmail.com> wrote:
>> >
>> > I wanted to share the results of some initial performance tests.
>> >
>> > This is from the log4j-perf FileAppenderBenchmark, starting with 1 thread, ending at 64 threads. It compares Logback to Log4j 1.2 to Log4j 2.
>> >
>> > Point of interest for me is "direct enc": use the garbage-free Layout.encode(LogEvent, ByteBufferDestination), vs. "allocate": create byte[] and Strings by calling Layout.toByteArray().
>> >
>> > <FileAppenderLinux2.6.png>
>> >
>> > Looks like at the moment garbage-free is better with a single thread and allocating is better with more threads.
>> >
>> > This is because the current implementation locks on the OutputStreamManager while writing into the shared buffer.
>> >
>> > I'm very happy with this initial result.
>> > We can probably improve on this with a threadlocal byte buffer so we only need to lock when copying that threadlocal buffer into the shared buffer.
>> >
>> > What is also interesting is how much better Log4j 2 is compared to Logback and Log4j, especially with more than one thread.
>> >
>> > Command to run the tests:
>> > java -Dlog4j2.enable.direct.encoders=true -jar benchmarks-LOG4J2-1343-20160411.jar ".*FileAppender.*" -f 1 -wi 10 -i 20 -bm thrpt -tu s -t 1
>> >
>> > (increase threads with -t 2, -t 4 etc, use log4j2.enable.direct.encoders=false to use Layout.toByteArray())
>> >
>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
>> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>
Re: FileAppender synchronous logging performance
Posted by Robin Coe <rc...@gmail.com>.
Is that total msg/s across all threads or per thread? I expect it's per
thread but wanted to be sure, as the single threaded performance would make
it seem that you shouldn't run multithreaded.
On Tue, Apr 12, 2016 at 2:27 PM, Ralph Goers <ra...@dslextreme.com>
wrote:
> Something you could add to the performance page on the site perhaps?
>
> If I am not mistaken Logback still has code that doesn’t use
> UnsynchronizedAppenderBase so it would have more locking contention. But I
> don’t know if this test is one of them. I would agree that a ThreadLocal
> byte buffer might make a difference.
>
> Ralph
>
> > On Apr 12, 2016, at 9:30 AM, Remko Popma <re...@gmail.com> wrote:
> >
> > I wanted to share the results of some initial performance tests.
> >
> > This is from the log4j-perf FileAppenderBenchmark, starting with 1
> thread, ending at 64 threads. It compares Logback to Log4j 1.2 to Log4j 2.
> >
> > Point of interest for me is "direct enc": use the garbage-free
> Layout.encode(LogEvent, ByteBufferDestination), vs. "allocate": create
> byte[] and Strings by calling Layout.toByteArray().
> >
> > <FileAppenderLinux2.6.png>
> >
> > Looks like at the moment garbage-free is better with a single thread and
> allocating is better with more threads.
> >
> > This is because the current implementation locks on the
> OutputStreamManager while writing into the shared buffer.
> >
> > I'm very happy with this initial result.
> > We can probably improve on this with a threadlocal byte buffer so we
> only need to lock when copying that threadlocal buffer into the shared
> buffer.
> >
> > What is also interesting is how much better Log4j 2 is compared to
> Logback and Log4j, especially with more than one thread.
> >
> > Command to run the tests:
> > java -Dlog4j2.enable.direct.encoders=true -jar
> benchmarks-LOG4J2-1343-20160411.jar ".*FileAppender.*" -f 1 -wi 10 -i 20
> -bm thrpt -tu s -t 1
> >
> > (increase threads with -t 2, -t 4 etc, use
> log4j2.enable.direct.encoders=false to use Layout.toByteArray())
> >
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>
>
Re: FileAppender synchronous logging performance
Posted by Ralph Goers <ra...@dslextreme.com>.
Something you could add to the performance page on the site perhaps?
If I am not mistaken Logback still has code that doesn’t use UnsynchronizedAppenderBase so it would have more locking contention. But I don’t know if this test is one of them. I would agree that a ThreadLocal byte buffer might make a difference.
Ralph
> On Apr 12, 2016, at 9:30 AM, Remko Popma <re...@gmail.com> wrote:
>
> I wanted to share the results of some initial performance tests.
>
> This is from the log4j-perf FileAppenderBenchmark, starting with 1 thread, ending at 64 threads. It compares Logback to Log4j 1.2 to Log4j 2.
>
> Point of interest for me is "direct enc": use the garbage-free Layout.encode(LogEvent, ByteBufferDestination), vs. "allocate": create byte[] and Strings by calling Layout.toByteArray().
>
> <FileAppenderLinux2.6.png>
>
> Looks like at the moment garbage-free is better with a single thread and allocating is better with more threads.
>
> This is because the current implementation locks on the OutputStreamManager while writing into the shared buffer.
>
> I'm very happy with this initial result.
> We can probably improve on this with a threadlocal byte buffer so we only need to lock when copying that threadlocal buffer into the shared buffer.
>
> What is also interesting is how much better Log4j 2 is compared to Logback and Log4j, especially with more than one thread.
>
> Command to run the tests:
> java -Dlog4j2.enable.direct.encoders=true -jar benchmarks-LOG4J2-1343-20160411.jar ".*FileAppender.*" -f 1 -wi 10 -i 20 -bm thrpt -tu s -t 1
>
> (increase threads with -t 2, -t 4 etc, use log4j2.enable.direct.encoders=false to use Layout.toByteArray())
>
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org
Re: FileAppender synchronous logging performance
Posted by Matt Sicker <bo...@gmail.com>.
Very interesting results!
On 12 April 2016 at 11:30, Remko Popma <re...@gmail.com> wrote:
> I wanted to share the results of some initial performance tests.
>
> This is from the log4j-perf FileAppenderBenchmark, starting with 1 thread,
> ending at 64 threads. It compares Logback to Log4j 1.2 to Log4j 2.
>
> Point of interest for me is "direct enc": use the garbage-free
> Layout.encode(LogEvent, ByteBufferDestination), vs. "allocate": create
> byte[] and Strings by calling Layout.toByteArray().
>
>
>
> Looks like at the moment garbage-free is better with a single thread and
> allocating is better with more threads.
>
> This is because the current implementation locks on the
> OutputStreamManager while writing into the shared buffer.
>
> I'm very happy with this initial result.
> We can probably improve on this with a threadlocal byte buffer so we only
> need to lock when copying that threadlocal buffer into the shared buffer.
>
> What is also interesting is how much better Log4j 2 is compared to Logback
> and Log4j, especially with more than one thread.
>
> Command to run the tests:
> java -Dlog4j2.enable.direct.encoders=true -jar
> benchmarks-LOG4J2-1343-20160411.jar ".*FileAppender.*" -f 1 -wi 10 -i 20
> -bm thrpt -tu s -t 1
>
> (increase threads with -t 2, -t 4 etc, use
> log4j2.enable.direct.encoders=false to use Layout.toByteArray())
>
>
--
Matt Sicker <bo...@gmail.com>