We use basic features of Log4J and have not experienced measurable performance
issues on our end. But other tools we use have gone through ups and downs such
as Eclipse, Tomcat or Pentaho Kettle.
And in spite of your paid job, your help in this forum is constant. It's
amazing and inspiring to see. Thanks to you and all the team.
Laurent Hasson
Co-Founder and CTO
CapsicoHealth Inc.
-----Original Message-----
From: Ralph Goers <ralph.go...@dslextreme.com>
Sent: Thursday, November 19, 2020 22:11
To: Log4J Users List <log4j-user@logging.apache.org>
Subject: Re: log4j2 performance issues with Java 11
If you have encountered performance issues my recommendation is to get YourKit
and take snapshots of CPU usage. If you capture just a few minutes of “normal”
activity I’d be happy to look at the snapshots and investigate whatever might
be going on. I should note that I do have a paid day job so these will need to
be related to Log4j 2 and you should not expect instant turnaround.
Ralph
> On Nov 19, 2020, at 7:59 PM, Laurent Hasson <l...@capsicohealth.com> wrote:
>
> This is a great thread. Thank you Lisa and the Log4J team for getting to the
> bottom of this.
>
> Moving to Java 11 has also been somewhat traumatic for us... this breakdown
> of log4j performance at the feature level is fascinating to see. I hope some
> article comes out of this once you all have figured it out.
>
> Thank you,
> Laurent.
>
> Sent from my BlackBerry - the most secure mobile device
> From: ralph.go...@dslextreme.com
> Sent: November 19, 2020 21:07
> To: lbru...@protonmail.com
> Reply-to: log4j-user@logging.apache.org
> Cc: volkan.yaz...@gmail.com; log4j-user@logging.apache.org
> Subject: Re: log4j2 performance issues with Java 11
>
> I am assuming you captured the snapshot from your profiling session? If so it
> would be great it you could send it to me. I can email you privately with a
> dropbox location where you can place the file if that will work for you.
>
> FWIW, I find your results surprising as all %logger{36} should be doing is
> truncating the logger name and including it. I would have expected formatting
> the time or including the location info to be slower than dealing with the
> logger.
>
> Thanks,
> Ralph
>
>> On Nov 19, 2020, at 7:00 PM, Lisa Ruby <lbru...@protonmail.com> wrote:
>>
>> Hi,
>>
>> I have what I hope will be some useful information. I did what Volkan
>> suggested and removed each log option mostly one at a time. I've pasted in
>> the information I collected below. It appears that it's the %logger{36}
>> option that is making the Console logging go so slow. Taking out other
>> options speeds things up some, but taking out only %logger gets it to just
>> about the same performance as on Java 8. Maybe that's only because less text
>> is going to the Console? Don't know. Below this table is information from
>> Profiling.
>>
>>
>> Verified same things are being logged in both Java 8 and Java 11
>>
>>
>>
>> Java Version Test Description Time in seconds for Startup after
>> Login Comments
>> 8 Baseline test with nothing changed in app or log4j2.xml file 4
>> 11 Baseline test with nothing changed in app or log4j2.xml file 25.7
>> 11 Removed Rolling Log File logging from log4j2.xml. So Console only
>> logging, no other changes to log4j2.xml 24.13
>> 11 Removed only %L, Console only logging 23.78
>> 11 Removed only [%t] Console only logging 16.79
>> 11 Removed only %d{ISO8601}, Console only logging 18.11
>> 11 Removed %d{ISO8601} and [%t], Console only logging 11.17
>> 11 Removed only %logger{36}, Console only logging 5.89
>>
>>
>> PROFILING
>> -----------------
>> I downloaded a trial version of the YourKit Java Profiler and have tried
>> playing with it. I am running it as follows:
>>
>> I installed the Netbeans plugin
>> Set the Options to Startup with CPU Profiling/Sampling.
>> Ran Profile Main Project
>> I then logged into my application and once it's fully started I
>> checked the Method List and some other things I don't see
>> java.util.Stackwalker listed in the Method List This is everything I
>> see that is not my application class methods
>>
>> <pnbklipoafhdmcip.png>
>>
>> <olmafefjabpcodjc.png>
>>
>>
>> Here is what it shows for the Log4j2 Thread in the Events by Table
>>
>> <ealilbphadpnkmce.png>
>>
>> The profiler is also warning me that there may be some deadlocks. It is
>> beyond my knowledge level at this time to try to determine if there is
>> actually a problem. I suspect not, but don't know for sure. This is what it
>> tells me:
>>
>> <maephhbjpobfomco.png>
>> <efheigahggegodgi.png>
>>
>>
>> Let me know if there is any other information I can collect.
>>
>> Lisa
>>
>> On 11/19/2020 5:51 AM, Volkan Yazıcı wrote:
>>> In the light of what Ralph mentioned about %L pattern, @Lisa, would you
>>> mind seeing if simplifying the pattern (that is, removing certain
>>> directives bit by bit, e.g., starting with %L) helps? Pinning down the
>>> actual smoking gun would help us a lot.
>>>
>>> On Wed, Nov 18, 2020 at 4:50 PM Ralph Goers <ralph.go...@dslextreme.com
>>> <mailto:ralph.go...@dslextreme.com>> wrote:
>>> Is there any chance you could run your application under YourKit and
>>> profile startup?
>>>
>>> Your partner uses %L so each log event needs to locate the location of the
>>> caller. In Java 8 that used the com.sun.Reflection class but that was
>>> removed in Java 9 so in Java 11 it would be using java.util.StackWalker. I
>>> suspect the majority of the time will be there. I have made several
>>> attempts to make that faster but haven’t seemed to find something that
>>> works for everybody. So providing a profiling snapshot would help
>>> enormously.
>>>
>>> FWIW, Logging to the Console is known to be very slow, but I don’t believe
>>> it should have changed that much between Java 8 and 11.
>>>
>>> Ralph
>>>
>>>> On Nov 17, 2020, at 11:11 PM, Lisa Ruby <lbru...@protonmail.com
>>>> <mailto:lbru...@protonmail.com>.INVALID> wrote:
>>>>
>>>> I am working on moving my Java application development from Java 8
>>>> and JavaFX 8 to Java 11 and JavaFX 11, and am seeing a large
>>>> performance degradation in log4j between Java 8 and Java 11.
>>>>
>>>> I've found these two issues that appear to have been addressed.
>>>> Assuming whatever changes/fixes were involved got included in the
>>>> latest releases, they have not fixed the issue I am seeing.
>>>>
>>>> https://github.com/line/armeria/issues/2306
>>>> <https://github.com/line/armeria/issues/2306>
>>>> https://issues.apache.org/jira/browse/LOG4J2-2537
>>>> <https://issues.apache.org/jira/browse/LOG4J2-2537>
>>>>
>>>> For Java 11 I am using AdoptOpenJDK version 11.0.2, OpenJFX version
>>>> 11.0.2, log4j version 2.14.0 (also tried 2.13.3, and 2.12.1), and
>>>> NetBeans 12.0. In my Java 8 implementation I'm using log4j 2.12.1.
>>>> I can supply JDK version if needed.
>>>>
>>>> Below is a general representation of what my log4j xml config file
>>>> looks like. It's the same for Java 8 as for Java 11. I have a
>>>> Loggers entry for each class in my application. They are all
>>>> specified the same as the one shown here. In each class file I have code
>>>> that looks like this:
>>>>
>>>> private static final Logger logger =
>>>> LogManager.getLogger(ClassName.class.getName());
>>>>
>>>> XML File Sample
>>>>
>>>> <?xml version="1.0" encoding="UTF-8"?> <Configuration status="warn"
>>>> monitorinterval="15"> <Appenders>
>>>> <Console name="Console" target="SYSTEM_OUT">
>>>> <PatternLayout pattern="%d{ISO8601} [%t] %-5level %logger{36}
>>>> - %L - %msg%n"/>
>>>> </Console>
>>>> <RollingFile name="RollingLogFile" fileName="logs/app.log"
>>>> filePattern="logs/app-%i.log" >
>>>> <PatternLayout>
>>>> <pattern>%d{ISO8601}_%-5level_[%replace{%t}{stateofmyestate\.}{}]_%replace{%logger{36}}{stateofmyestate\.}{}_%L_%msg%n%ex</pattern>
>>>> </PatternLayout>
>>>> <Policies>
>>>> <SizeBasedTriggeringPolicy size="5 MB" />
>>>> </Policies>
>>>> <DefaultRolloverStrategy max="5"/>
>>>> </RollingFile>
>>>> </Appenders>
>>>> <Loggers>
>>>> <Logger name = "appname.classname" level = "trace"
>>>> additivity="false">
>>>> <AppenderRef ref="RollingLogFile"/>
>>>> <AppenderRef ref="Console"/>
>>>> </Logger>
>>>> <Root level="trace">
>>>> <AppenderRef ref="Console"/>
>>>> </Root>
>>>> </Loggers>
>>>> </Configuration>
>>>>
>>>> I have a lot of log messages, many of which are logged as the
>>>> application is starting. When using Java 11 the logging is causing
>>>> my application to take at least 6 times longer to start than with Java 8.
>>>> With Java 8 it takes between 3 and 4 seconds. With Java 11 it takes
>>>> 25 seconds. I have some other functionality that also does a lot of
>>>> logging when the log level is set to trace, and in that case the
>>>> performance goes from seconds in Java 8 to several minutes in Java 11.
>>>>
>>>> I've tried various things to troubleshoot, and it appears to be
>>>> something related to Console logging that is causing the
>>>> performance issue. If I remove the Console Appenders from my
>>>> configuration and leave only the RollingFile Appenders, the problem
>>>> goes away. If I do the opposite and remove the RollingFile
>>>> Appenders and leave the Console Appenders, I see a tiny improvement
>>>> in the performance, but it's still way worse than in Java 8. So far
>>>> I'm testing by running the application through NetBeans. I haven't
>>>> tried starting the application from a Windows Command window yet. Running
>>>> into some other issues doing that.
>>>>
>>>> Can anyone help me figure out if this is a log4j issue, or if there
>>>> is something I can change in how I'm using log4j with Java 11, so I
>>>> can resolve this issue?
>>>>
>>>> Thank you.
>>>>
>>>> Lisa Ruby
>>>>
>>>>
>>>>
>>>>
>>>> -------------------------------------------------------------------
>>>> -- To unsubscribe, e-mail:
>>>> log4j-user-unsubscr...@logging.apache.org
>>>> <mailto:log4j-user-unsubscr...@logging.apache.org>
>>>> For additional commands, e-mail: log4j-user-h...@logging.apache.org
>>>> <mailto:log4j-user-h...@logging.apache.org>
>>>>
>>>>
>>>
>>>
>>>
>>> --------------------------------------------------------------------
>>> - To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org
>>> <mailto:log4j-user-unsubscr...@logging.apache.org>
>>> For additional commands, e-mail: log4j-user-h...@logging.apache.org
>>> <mailto:log4j-user-h...@logging.apache.org>
>>>
>>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-user-h...@logging.apache.org
