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> >> >