Jenkins build is back to normal : Log4jBoot #9

2017-02-08 Thread Apache Jenkins Server
See 


-
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org



Re: Logback performance improvements

2017-02-08 Thread Apache
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.julFilethrpt   1094.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.logbackFilethrpt   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.julFilethrpt   1067.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.logbackFilethrpt   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.julFilethrpt   1075.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.logbackFilethrpt   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.julFilethrpt   1039.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.logbackFilethrpt   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  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 > > 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 >> > 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 > 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 > wrote:
 Is this something we can improve performance on by implementing a file 
 appender based on FileChannel or 

[jira] [Commented] (LOG4J2-1810) Upgrade Logback to version 1.2

2017-02-08 Thread ASF subversion and git services (JIRA)

[ 
https://issues.apache.org/jira/browse/LOG4J2-1810?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15859021#comment-15859021
 ] 

ASF subversion and git services commented on LOG4J2-1810:
-

Commit 84772ea2189d87a821092977f8eb8d4d936600ee in logging-log4j-boot's branch 
refs/heads/master from [~jvz]
[ https://git-wip-us.apache.org/repos/asf?p=logging-log4j-boot.git;h=84772ea ]

[LOG4J2-1810] Upgrade to Logback 1.2.0


> Upgrade Logback to version 1.2
> --
>
> Key: LOG4J2-1810
> URL: https://issues.apache.org/jira/browse/LOG4J2-1810
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Core
>Affects Versions: 2.8
>Reporter: Ralph Goers
>Priority: Minor
> Fix For: boot-1.0-alpha1, 2.8.1
>
>




--
This message was sent by Atlassian JIRA
(v6.3.15#6346)

-
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org



[jira] [Updated] (LOG4J2-1810) Upgrade Logback to version 1.2

2017-02-08 Thread Matt Sicker (JIRA)

 [ 
https://issues.apache.org/jira/browse/LOG4J2-1810?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Matt Sicker updated LOG4J2-1810:

Fix Version/s: boot-1.0-alpha1

> Upgrade Logback to version 1.2
> --
>
> Key: LOG4J2-1810
> URL: https://issues.apache.org/jira/browse/LOG4J2-1810
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Core
>Affects Versions: 2.8
>Reporter: Ralph Goers
>Priority: Minor
> Fix For: boot-1.0-alpha1, 2.8.1
>
>




--
This message was sent by Atlassian JIRA
(v6.3.15#6346)

-
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org



[jira] [Commented] (LOG4J2-1810) Upgrade Logback to version 1.2

2017-02-08 Thread ASF subversion and git services (JIRA)

[ 
https://issues.apache.org/jira/browse/LOG4J2-1810?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15859014#comment-15859014
 ] 

ASF subversion and git services commented on LOG4J2-1810:
-

Commit 311fce5171e9fd197b3f5e35342df173d61c2842 in logging-log4j2's branch 
refs/heads/master from [~ralph.go...@dslextreme.com]
[ https://git-wip-us.apache.org/repos/asf?p=logging-log4j2.git;h=311fce5 ]

LOG4J2-1810 - Update to Logback 1.2


> Upgrade Logback to version 1.2
> --
>
> Key: LOG4J2-1810
> URL: https://issues.apache.org/jira/browse/LOG4J2-1810
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Core
>Affects Versions: 2.8
>Reporter: Ralph Goers
>Priority: Minor
> Fix For: 2.8.1
>
>




--
This message was sent by Atlassian JIRA
(v6.3.15#6346)

-
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org



[jira] [Reopened] (LOG4J2-1810) Upgrade Logback to version 1.1.10

2017-02-08 Thread Ralph Goers (JIRA)

 [ 
https://issues.apache.org/jira/browse/LOG4J2-1810?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Ralph Goers reopened LOG4J2-1810:
-

Update to Logback 1.2

> Upgrade Logback to version 1.1.10
> -
>
> Key: LOG4J2-1810
> URL: https://issues.apache.org/jira/browse/LOG4J2-1810
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Core
>Affects Versions: 2.8
>Reporter: Ralph Goers
>Priority: Minor
> Fix For: 2.8.1
>
>




--
This message was sent by Atlassian JIRA
(v6.3.15#6346)

-
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org



[jira] [Updated] (LOG4J2-1810) Upgrade Logback to version 1.2

2017-02-08 Thread Ralph Goers (JIRA)

 [ 
https://issues.apache.org/jira/browse/LOG4J2-1810?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Ralph Goers updated LOG4J2-1810:

Summary: Upgrade Logback to version 1.2  (was: Upgrade Logback to version 
1.1.10)

> Upgrade Logback to version 1.2
> --
>
> Key: LOG4J2-1810
> URL: https://issues.apache.org/jira/browse/LOG4J2-1810
> Project: Log4j 2
>  Issue Type: Bug
>  Components: Core
>Affects Versions: 2.8
>Reporter: Ralph Goers
>Priority: Minor
> Fix For: 2.8.1
>
>




--
This message was sent by Atlassian JIRA
(v6.3.15#6346)

-
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org



Re: Java 9

2017-02-08 Thread Apache
Sorry, I forgot to reply. The specific thread begins with 
http://mail.openjdk.java.net/pipermail/core-libs-dev/2016-May/040826.html 
 and 
the specific message is 
http://mail.openjdk.java.net/pipermail/core-libs-dev/2016-May/041029.html 
 
where they recommend getting the caller’s stack frame from each logging method.

Ralph

> On Feb 6, 2017, at 5:19 PM, Remko Popma  wrote:
> 
> Can you point me at some info on that? What massive changes are needed?
> 
> Remko
> 
> Sent from my iPhone
> 
> On Feb 7, 2017, at 1:36, Apache  > wrote:
> 
>> I fixed the only problem I could find last week. However, we still have more 
>> to do as we really need to support the StackWalker API and the “right” way 
>> to do it would require massive changes. I also need to benchmark the cost of 
>> invoking the StackWalker API to return the method’s caller to see what the 
>> impact would be to do it on every logging call.
>> 
>> Ralph
>> 
>>> On Feb 6, 2017, at 9:15 AM, Matt Sicker >> > wrote:
>>> 
>>> I remember Ralph mentioned that he tested it out and found that it worked 
>>> pretty well. See issue: >> >
>>> 
>>> On 6 February 2017 at 09:56, Remko Popma >> > wrote:
>>> I haven't had a chance to look at this yet, but is the new stack walking 
>>> API in Java 9 of any use for us? I believe applications/libraries like 
>>> Log4j were supposed to be the drivers behind this feature, but last time I 
>>> checked they were not going to cater for our use case (inspect the stack 
>>> from the bottom up)... 
>>> 
>>> From a functional point of view, is anybody aware of anything outstanding 
>>> we need to fix for Log4j 2 to work correctly on Java 9?
>>> 
>>> Remko
>>> 
>>> 
>>> 
>>> -- 
>>> Matt Sicker >
>> 



Re: Logback performance improvements

2017-02-08 Thread Apache
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  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 > > 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 >> > 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 >> > 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 >> > 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 > 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  > wrote:
> 
> This is all in a synchronous appender, right? Either way, that's rather 
> interesting.
> 
> On 6 February 2017 at 07:54, Apache  > 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 > > 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 > > 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 >> > 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" >> > 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.julFilethrpt   20
>>> 98187.673 ±  4935.712  ops/s
>>> o.a.l.l.p.j.FileAppenderBenchmark.log4j1File thrpt   20   
>>> 842374.496 ±  6762.712  ops/s

Re: Logback performance improvements

2017-02-08 Thread Apache
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  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 > > 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 > > 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 > > 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 >> > 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 > wrote:
 
 This is all in a synchronous appender, right? Either way, that's rather 
 interesting.
 
 On 6 February 2017 at 07:54, Apache > 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  > 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  > 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 > > 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" > > 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.julFilethrpt   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.logbackFilethrpt   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.
>> 

FINAL REMINDER: CFP for ApacheCon closes February 11th

2017-02-08 Thread Rich Bowen
Dear Apache Enthusiast,

This is your FINAL reminder that the Call for Papers (CFP) for ApacheCon
Miami is closing this weekend - February 11th. This is your final
opportunity to submit a talk for consideration at this event.

This year, we are running several mini conferences in conjunction with
the main event, so if you're submitting for one of those events, please
pay attention to the instructions below.

Apache: Big Data
* Event information:
http://events.linuxfoundation.org/events/apache-big-data-north-america
* CFP:
http://events.linuxfoundation.org/events/apache-big-data-north-america/program/cfp

Apache: IoT (Internet of Things)
* Event Information: http://us.apacheiot.org/
* CFP -
http://events.linuxfoundation.org/events/apachecon-north-america/program/cfp
(Indicate 'IoT' in the Target Audience field)

CloudStack Collaboration Conference
* Event information: http://us.cloudstackcollab.org/
* CFP -
http://events.linuxfoundation.org/events/apachecon-north-america/program/cfp
(Indicate 'CloudStack' in the Target Audience field)

FlexJS Summit
* Event information - http://us.apacheflexjs.org/
* CFP -
http://events.linuxfoundation.org/events/apachecon-north-america/program/cfp
(Indicate 'Flex' in the Target Audience field)

TomcatCon
* Event information - https://tomcat.apache.org/conference.html
* CFP -
http://events.linuxfoundation.org/events/apachecon-north-america/program/cfp
(Indicate 'Tomcat' in the Target Audience field)

All other topics and projects
* Event information -
http://events.linuxfoundation.org/events/apachecon-north-america/program/about
* CFP -
http://events.linuxfoundation.org/events/apachecon-north-america/program/cfp

Admission to any of these events also grants you access to all of the
others.

Thanks, and we look forward to seeing you in Miami!

-- 
Rich Bowen
VP Conferences, Apache Software Foundation
rbo...@apache.org
Twitter: @apachecon



(You are receiving this email because you are subscribed to a dev@ or
users@ list of some Apache Software Foundation project. If you do not
wish to receive email from these lists any more, you must follow that
list's unsubscription procedure. View the headers of this message for
unsubscription instructions.)

-
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org



Re: Logback performance improvements

2017-02-08 Thread Remko Popma
Is it possible that the memory mapped file starts resizing and remapping at 
this point?

Sent from my iPhone

> On Feb 8, 2017, at 15:12, Apache  wrote:
> 
> I used a ThreadLocal byte buffer and wrote to the file channel and if 
> anything, it performed slightly worse. This is probably because I had to 
> write after ever event, not when the buffer was full, otherwise the ordering 
> of events in the output would get messed up.
> 
> I decided to throw the MemoryMappedFileAppender into the mix and I got some 
> very strange behavior. Using Logback 1.1.10 the overall results with 4 
> threads were:
> 
> Benchmark Mode  Samples Score 
> Error   Units
> o.a.l.l.p.j.FileAppenderBenchmark.julFilethrpt   1098.886 ±  
> 10.855  ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j1File thrpt   10   826.640 ±  
> 14.219  ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2File thrpt   10  1861.518 ± 
> 139.885  ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2MMF  thrpt   10  1478.489 ± 
> 970.526  ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.log4j2RAF  thrpt   10  2023.783 ±  
> 41.284  ops/ms
> o.a.l.l.p.j.FileAppenderBenchmark.logbackFilethrpt   10   997.495 ±  
> 42.801  ops/ms
> 
> What is strange is the actual output from the run for the 
> MemoryMappedFileAppender. You will notice that it starts off like a bat out 
> of hell but then bogs down terribly. I’d love to know why.
> 
> # VM invoker: 
> /Library/Java/JavaVirtualMachines/jdk1.8.0_65.jdk/Contents/Home/jre/bin/java
> # VM options: 
> # Warmup: 10 iterations, 1 s each
> # Measurement: 10 iterations, 1 s each
> # Timeout: 10 min per iteration
> # Threads: 4 threads, will synchronize iterations
> # Benchmark mode: Throughput, ops/time
> # Benchmark: org.apache.logging.log4j.perf.jmh.FileAppenderBenchmark.log4j2MMF
> 
> # Run progress: 50.00% complete, ETA 00:01:14
> # Fork: 1 of 1
> # Warmup Iteration   1: 2546.240 ops/ms
> # Warmup Iteration   2: 3071.504 ops/ms
> # Warmup Iteration   3: 2980.503 ops/ms
> # Warmup Iteration   4: 2709.490 ops/ms
> # Warmup Iteration   5: 2661.919 ops/ms
> # Warmup Iteration   6: 2610.875 ops/ms
> # Warmup Iteration   7: 2663.431 ops/ms
> # Warmup Iteration   8: 2675.847 ops/ms
> # Warmup Iteration   9: 2755.735 ops/ms
> # Warmup Iteration  10: 2666.353 ops/ms
> Iteration   1: 2577.419 ops/ms
> Iteration   2: 2804.161 ops/ms
> Iteration   3: 1179.059 ops/ms
> Iteration   4: 1167.719 ops/ms
> Iteration   5: 1170.686 ops/ms
> Iteration   6: 1246.053 ops/ms
> Iteration   7: 1173.593 ops/ms
> Iteration   8: 1196.317 ops/ms
> Iteration   9: 1127.199 ops/ms
> Iteration  10: 1142.684 ops/ms
> 
> Ralph
> 
> 
>> On Feb 7, 2017, at 10:55 AM, Apache  wrote:
>> 
>> True, but I would still like to also see what difference it makes using the 
>> FileChannel instead of the OutputStream.
>> 
>> Ralph
>> 
>>> On Feb 7, 2017, at 9:45 AM, Remko Popma  wrote:
>>> 
>>> That is all doable but it may be a good idea to test if that is really 
>>> where the bottleneck is. 
>>> We could try whether we get better numbers if we remove the current 
>>> synchronization (ignoring any scrambled output, just for testing purposes).
>>> 
>>> 
 On Wed, Feb 8, 2017 at 1:40 AM, Apache  wrote:
 In looking at FileManager and OutputStreamManager it does have a 
 ByteBuffer but it requires synchronization. I am thinking it might make 
 more sense to have a ThreadLocal ByteBuffer and then pass that to 
 FileChannel.write() so that no synchronization is required.
 
 Ralph
 
> On Feb 7, 2017, at 9:36 AM, Matt Sicker  wrote:
> 
> Can't we use the ByteBuffers introduced in the GC-free epic? I was under 
> the impression that byte arrays being passed to appenders was created 
> from a ByteBuffer at this point, though I haven't really taken a close 
> look at this.
> 
> On 7 February 2017 at 10:05, Apache  wrote:
>> A FileChannel is guaranteed to be thread safe. You can obtain a 
>> FileChannel from a FlieOutputStream, so that would seem to imply that 
>> FileOutputStream might be thread-safe, but you can’t really know that 
>> without looking at the source. The problem is that FileChannel.write() 
>> takes a ByteBuffer whereas FileOutputStream.write() accepts a byte 
>> array. To be thread safe it would have to safely copy the byte array 
>> into the byte buffer to pass to the FileChannel. But FileOutputStream 
>> doesn’t use the FileChannel at all in Java 7. It calls a native method 
>> that doesn’t specify whether it is thread-safe or not, so simply 
>> removing the synchronization isn’t guaranteed to work properly. 
>> 
>> OTOH, RandomAccessFile doesn’t say that it is thread-safe either and we 
>> are not