From log4j-dev-return-49682-apmail-logging-log4j-dev-archive=logging.apache.org@logging.apache.org Tue Feb 7 00:23:16 2017 Return-Path: X-Original-To: apmail-logging-log4j-dev-archive@www.apache.org Delivered-To: apmail-logging-log4j-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 1ECD51926C for ; Tue, 7 Feb 2017 00:23:16 +0000 (UTC) Received: (qmail 61056 invoked by uid 500); 7 Feb 2017 00:23:16 -0000 Delivered-To: apmail-logging-log4j-dev-archive@logging.apache.org Received: (qmail 61011 invoked by uid 500); 7 Feb 2017 00:23:16 -0000 Mailing-List: contact log4j-dev-help@logging.apache.org; run by ezmlm Precedence: bulk List-Unsubscribe: List-Help: List-Post: List-Id: "Log4J Developers List" Reply-To: "Log4J Developers List" Delivered-To: mailing list log4j-dev@logging.apache.org Received: (qmail 61000 invoked by uid 99); 7 Feb 2017 00:23:15 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd2-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 07 Feb 2017 00:23:15 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd2-us-west.apache.org (ASF Mail Server at spamd2-us-west.apache.org) with ESMTP id 738151A041E for ; Tue, 7 Feb 2017 00:23:15 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd2-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 1.879 X-Spam-Level: * X-Spam-Status: No, score=1.879 tagged_above=-999 required=6.31 tests=[DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, HTML_MESSAGE=2, RCVD_IN_DNSWL_NONE=-0.0001, RCVD_IN_MSPIKE_H3=-0.01, RCVD_IN_MSPIKE_WL=-0.01, SPF_PASS=-0.001] autolearn=disabled Authentication-Results: spamd2-us-west.apache.org (amavisd-new); dkim=pass (2048-bit key) header.d=gmail.com Received: from mx1-lw-us.apache.org ([10.40.0.8]) by localhost (spamd2-us-west.apache.org [10.40.0.9]) (amavisd-new, port 10024) with ESMTP id UtU1P5TzRUfz for ; Tue, 7 Feb 2017 00:23:13 +0000 (UTC) Received: from mail-lf0-f53.google.com (mail-lf0-f53.google.com [209.85.215.53]) by mx1-lw-us.apache.org (ASF Mail Server at mx1-lw-us.apache.org) with ESMTPS id 69CE15F644 for ; Tue, 7 Feb 2017 00:23:12 +0000 (UTC) Received: by mail-lf0-f53.google.com with SMTP id z134so53914034lff.3 for ; Mon, 06 Feb 2017 16:23:12 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:in-reply-to:references:from:date:message-id:subject:to; bh=jedOgKbTHp5huCZVqUxVhYr6/S8uG8UyZEwoFYe6bRE=; b=Eg5jVBG/sNQjs8zRxGYZyzg6aaMNq6FgCmJ8OS3SaTqOhYwoFUSS6VpIPBRieYRjgp MrHHePJGO/XnRRLsEgckBUcFcTkK0OaOvLnC9Vi3h6U5vqcTbcPu5RoGN8j/c3bSkuXU XeSoAbi+2KQZgf88C47GJWyD2e1ihyd80C2r1esLj+KDtihVh/i+LlXD7Vv8jmLRfJJa sduXLYhkpzYlQABRRrZyRA5PRM/A5Fr2Qfn4ndpGGiJgSZch0/37Edc+faFtjKGyfRLz e4QuHWSSm+C/UvcJkPh9Pbko4zsQmRvHbLMjIPLwsY7t6ZLeNtSuc44QURP5pcFxD4LD Dgbg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:in-reply-to:references:from:date :message-id:subject:to; bh=jedOgKbTHp5huCZVqUxVhYr6/S8uG8UyZEwoFYe6bRE=; b=Va1D5MJUU5Pn6GXutdoIRCg4piHdqwxJXE37qheAx1+H6LffuAu6deSIKRfuAK2a0Z dvdV1r7z7NJVDBgs93g9rOhYznUSZFgObeC/NhnZVSTkUSt7qkGNcDVDV18wR4ZnONNb utk9+quuaSHnVipCoL+fiem/kDLnzEbeMNrYvFwT8/0BZRLwLnJorjdZTW7t8KUakrsr g4glz5w8OUkgR9AA04aPvDiuni1TghXLXrIdQx2quYzNRfuhBTcUj4Or6iIvfZSFF7vy yQjF8JUkfQuXQ1q0QsU7GyR2FBsrblp3oPy7OTy6yXFlMODfbqYjs0KJkuE+YL2ExaFj THIg== X-Gm-Message-State: AMke39n3k2Hgft8VQfK8D0vnrbDgTI5MAyaOdyVZm2LDOty2BSf/OzVxSaqf50tbHis1Jd0o3Wd48CTwa0ciZg== X-Received: by 10.25.202.83 with SMTP id h19mr4610633lfj.33.1486426990816; Mon, 06 Feb 2017 16:23:10 -0800 (PST) MIME-Version: 1.0 Received: by 10.25.158.76 with HTTP; Mon, 6 Feb 2017 16:23:10 -0800 (PST) In-Reply-To: References: <60624C7D-0CBA-46E6-AE86-018481DCDAF2@dslextreme.com> <9D9375FF-5EC1-4DC8-BB4A-0A867E29F3A0@dslextreme.com> <2693338C-1C0B-4DC5-8696-45114D3C3CBC@dslextreme.com> <91F75262-172A-40EE-919E-D873C32665BA@dslextreme.com> From: Matt Sicker Date: Mon, 6 Feb 2017 18:23:10 -0600 Message-ID: Subject: Re: Logback performance improvements To: Log4J Developers List Content-Type: multipart/alternative; boundary=f403045e9f50c5b2910547e5c01d --f403045e9f50c5b2910547e5c01d Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable 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/1cpb5D7qnyye4W0 >> RTlHUnXedYK98catNZytYIu5D91m0/edit#gid=3D0 >> >> I haven=E2=80=99t run the tests with Logback 1.2-SNAPSHOT but my numbers= for my >> two MacBooks are at https://docs.google.com/spread >> sheets/d/1L67IhmUVvyLBWtC6iq0TMj-j0vrbKsUKWuZV0Nlqisk/edit?usp=3Dsharing= . >> >> 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=E2=80=99s list that match mi= ne. 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 (wh= ich >>> appears to be the default), and memory mapped file appender. It'd be co= ol >>> 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=E2=80=99s. You also should capture the c= pubenchmark >>>> 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 Window= s >>>> 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.julFile thrpt 20 >>>>> 98187.673 =C2=B1 4935.712 ops/s >>>>> o.a.l.l.p.j.FileAppenderBenchmark.log4j1File thrpt 20 >>>>> 842374.496 =C2=B1 6762.712 ops/s >>>>> o.a.l.l.p.j.FileAppenderBenchmark.log4j2File thrpt 20 >>>>> 1853062.583 =C2=B1 67032.225 ops/s >>>>> o.a.l.l.p.j.FileAppenderBenchmark.log4j2RAF thrpt 20 >>>>> 2036011.226 =C2=B1 53208.281 ops/s >>>>> o.a.l.l.p.j.FileAppenderBenchmark.logbackFile thrpt 20 >>>>> 999667.438 =C2=B1 12074.003 ops/s >>>>> >>>>> I=E2=80=99ll have to try this on one my VMs at work. We don=E2=80=99t= run anything >>>>> directly on bare metal any more. >>>>> >>>>> Ralph >>>>> >>>>> On Feb 5, 2017, at 9:40 AM, Apache 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/1cpb5D7qny >>>>> ye4W0RTlHUnXedYK98catNZytYIu5D91m0/edit#gid=3D0. I suspect we have a >>>>> few optimizations we can make. >>>>> >>>>> Ralph >>>>> >>>>> >>>>> >>>> >>> >>> >>> -- >>> Matt Sicker >>> >>> >>> >> >> >> -- >> Matt Sicker >> >> >> >> > > > -- > Matt Sicker > --=20 Matt Sicker --f403045e9f50c5b2910547e5c01d Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable
I'm not sure if I'm looking in the right place, bu= t 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 AsynchronousFil= eChannel instead of OutputStream?

On 6 February 2017 at 17:50, A= pache <ralph.goers@dslextreme.com> wrote:
Ceki has = updated his numbers to include those reported on the mailing list.=C2=A0https://docs.google.com/spreadsheets/d/1cpb5D7qnyye4W0RTlHUnXedYK98catNZytYIu5D91m0/ed= it#gid=3D0

I haven=E2=80=99t run the tests wit= h Logback 1.2-SNAPSHOT but my numbers for my two MacBooks are at https://docs.google.com/spr= eadsheets/d/1L67IhmUVvyLBWtC6iq0TMj-j0vrbKsUKWuZV0Nlqisk/edit?usp=3Dsharing.=C2=A0

Ralph

On Feb 6, 2017, at 9:33 AM, Apache <ralph.goers@dslextreme.com> wro= te:

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=E2=80=99s= list that match mine.=C2=A0 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 t= he log4j side: file appender with 256k buffer size, random access file appe= nder with 256k buffer size (which appears to be the default), and memory ma= pped file appender. It'd be cool to see how these compose with async lo= gging 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=C2=A0to compare your results to Ce= ki=E2=80=99s.=C2=A0 You also should capture the cpubenchmark speed of your = processor and get the speed of your hard drive. I used Blackmagic speed tes= t 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 Gr= egory <garyd= gregory@gmail.com> wrote:

If you want, I can run tests on Windo= ws 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@d= slextreme.com> wrote:
I guess my MacBook Pro mu= st fit in the Slow CPU/Fast Hard drive category. With Logback 1.10 and -t 4= =C2=A0now get

Benchmark =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 Mode=C2=A0 S= amples=C2=A0 =C2=A0 =C2=A0 =C2=A0 Score =C2=A0 =C2=A0 =C2=A0 Error=C2=A0 Un= its
o.a.l.l.p.j.FileAppenderBenchmark= .julFile=C2=A0 =C2=A0 =C2=A0 =C2=A0 thrpt =C2=A0 =C2=A0 =C2=A0 20=C2=A0 =C2= =A0 98187.673 =C2=B1=C2=A0 4935.712=C2=A0 ops/s
o.a.l.l.p.j.FileAppenderBenchmark.log4j1File =C2=A0 =C2=A0 thrpt= =C2=A0 =C2=A0 =C2=A0 20 =C2=A0 842374.496 =C2=B1=C2=A0 6762.712=C2=A0 ops/= s
o.a.l.l.p.j.FileAppenderBenchmark.l= og4j2File =C2=A0 =C2=A0 thrpt =C2=A0 =C2=A0 =C2=A0 20=C2=A0 1853062.583 =C2= =B1 67032.225=C2=A0 ops/s
= o.a.l.l.p.j.File= AppenderBenchmark.log4j2RAF=C2=A0 =C2=A0 =C2=A0 thrpt =C2=A0 =C2=A0 = =C2=A0 20=C2=A0 2036011.226 =C2=B1 53208.281=C2=A0 ops/s
o.a.l.l.p.j.FileAppenderBenchmark.logbackFile=C2=A0 =C2= =A0 thrpt =C2=A0 =C2=A0 =C2=A0 20 =C2=A0 999667.438 =C2=B1 12074.003=C2=A0 = ops/s

I=E2=80=99ll have to try this on one my VMs at work. We don=E2=80= =99t 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 FileAppende= r. See=C2=A0= https://logback.qos.ch/news.html=C2=A0and=C2=A0https://docs.google.com/spreadsheets/= d/1cpb5D7qnyye4W0RTlHUnXedYK98catNZytYIu5D91m0/edit#gid=3D0. = I suspect we have a few optimizations we can make.

Ralph=





--
Matt Sicker <boards@gmail.com>




--
Matt S= icker <boards@gmai= l.com>





= --
Matt Sic= ker <boards@gmail.= com>


--
Matt Sicker <boards@gmail.com>=
--f403045e9f50c5b2910547e5c01d--