Hello Ralph, I have done my tests with Java 8, but it seems that there is not different behaviour when using Java 11.
I have created a JIRA ticket: https://issues.apache.org/jira/browse/LOG4J2-2644 My test code can be found at: https://github.com/hupfdule/LoggingPerformanceTest Best regards Marco On Tue, Jun 25, 2019 at 09:41:38PM -0700, Ralph Goers wrote: > Thanks for this info. I will take a look at your tests in the next few days. > What version of Java were you running with? The method of getting the stack > trace info changed for both JUL and Log4j in JDK 9. > > Ralph > > > On Jun 24, 2019, at 11:52 PM, m...@mherrn.de wrote: > > > > Hi, > > > > according to https://logging.apache.org/log4j/2.x/performance.html logging > > with location information should be roughly the same performance for JUL > > and Log4j2. > > > > However I made a few comparisons between Log4j2 and JUL and in this case > > Log4j2 is much faster than JUL when omitting location information, but is > > considerably slower when logging with location information. > > > > Those are the results: > > > > JUL without location information : 32.162s > > JUL with location information : 21.682s > > Log4j2 without location information: 4.168s > > Log4j2 with location information : 59.000s > > > > In each case I logged 1500000 simple log statements (only a fixed string) > > and compared the timestamp of the first and the last generated log > > statement. Above you see the time spent between the first and the last log > > statement. > > I did these tests several times and the results are equal each time. > > > > In all cases I logged to a RollingFileAppender (or JULs equivalent). > > I assume that JUL with location information is faster than JUL without > > location information is because for JUL with location information I used a > > custom Formatter that doesn't support any configuration whereas I was > > using a SimpleFormatter with a specified formatstring for JUL without log > > information. > > > > It should be noted that I didn't use the Log4j2 API, but instead used the > > JUL logging API and used the log4j-jul-bridge to actually use Log4j2 > > instead of the JUL implementation! > > > > I want to pay special attention to the difference when logging with > > location information, since I am puzzled that Log4j2 is that much slower > > than JUL in that case. > > > > The implementation of my custom Formatter is this: > > > > public class OneLineFormatter extends Formatter { > > private static final String LINE_SEPARATOR = > > System.getProperty("line.separator"); > > private static final DateFormat DATE_FORMAT= new > > SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSSS"); > > > > > > @Override > > public String format(final LogRecord record) { > > final StringBuilder sb = new StringBuilder(); > > > > final String dateString= DATE_FORMAT.format(new > > Date(record.getMillis())); > > > > sb.append(dateString) > > .append(" ") > > .append(getLogLevelString(record.getLevel())) > > .append(" [") > > .append(record.getSourceClassName()) > > .append("#") > > .append(record.getSourceMethodName()).append("()") > > .append("]") > > .append(" - ") > > .append(formatMessage(record)) > > .append(LINE_SEPARATOR); > > > > if (record.getThrown() != null) { > > try { > > StringWriter sw = new StringWriter(); > > PrintWriter pw = new PrintWriter(sw); > > record.getThrown().printStackTrace(pw); > > pw.close(); > > sb.append(sw.toString()); > > } catch (Exception ex) { > > // ignore > > } > > } > > > > return sb.toString(); > > } > > > > private String getLogLevelString(final Level level){ > > return String.format("%1$-7s", level.getName()); > > } > > } > > > > The log4j2 configuration I used is this: > > > > <Configuration monitorinterval="30" status="info" strict="true"> > > <Properties> > > <Property name="filename">logs/log4j2-with-method.log</Property> > > <Property > > name="filepattern">logs/log4j2-with-method.log.%i.gz</Property> > > </Properties> > > <Appenders> > > <Appender type="RollingFile" name="File" fileName="${filename}" > > filePattern="${filepattern}" bufferedIO="true"> > > <Policies> > > <OnStartupTriggeringPolicy /> > > <SizeBasedTriggeringPolicy size="100mb"/> > > </Policies> > > <DefaultRolloverStrategy max="15" fileIndex="min" /> > > <Layout type="PatternLayout" pattern="%d %-6p [%C#%M] (%t) %m > > %ex%n" /> > > </Appender> > > </Appenders> > > <Loggers> > > <Root level="INFO"> > > <AppenderRef ref="File" /> > > </Root> > > <Logger name="LPT_SIMPLE" level="ALL" /> > > </Loggers> > > </Configuration> > > > > > > I don't think there is anything special. Since when logging without > > location information Log4j2 is much faster than JUL there must be a > > difference between getting the location information. My above mentioned > > custom formatter uses the methods java.util.LogRecord#getSourceClassName() > > and java.util.LogRecord#getSourceMethodName() for obtaining that > > information. I haven't looked into how Log4j2 does it, but it seems to be > > much less efficient. > > > > Can someone explain why Log4j2 is that much slower in that case? > > Is there another way in Log4j2 to get the location information that > > performs as fast as JUL? > > > > > > Best regards > > Marco > > > > > > --------------------------------------------------------------------- > > To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org > > For additional commands, e-mail: 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 > --------------------------------------------------------------------- To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org For additional commands, e-mail: log4j-user-h...@logging.apache.org
