输出格式优化前
经过测试查看每秒的并发量平均只有110多如下图
通过查看JVM虚拟机发现很多日志线程出现BLOCKED，如下
"http-saoma%2F192.168.6.162-8097-132" daemon prio=10 tid=0x00002aaab88e4800 nid=0x2c8e runnable [0x0000000045274000] java.lang.Thread.State: BLOCKED at java.lang.Throwable.getStackTraceElement(Native Method) at java.lang.Throwable.getOurStackTrace(Throwable.java:591) - locked <0x00000007691390d0> (a java.lang.Throwable) at java.lang.Throwable.getStackTrace(Throwable.java:582) at sun.reflect.GeneratedMethodAccessor29.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.apache.log4j.spi.LocationInfo.<init>(LocationInfo.java:139) at org.apache.log4j.spi.LoggingEvent.getLocationInformation(LoggingEvent.java:253) at org.apache.log4j.helpers.PatternParser$LocationPatternConverter.convert(PatternParser.java:500) at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:65) at org.apache.log4j.PatternLayout.format(PatternLayout.java:506) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:310) at org.apache.log4j.DailyRollingFileAppender.subAppend(DailyRollingFileAppender.java:369) at org.apache.log4j.WriterAppender.append(WriterAppender.java:162) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251) - locked <0x0000000780fb1e00> (a org.apache.log4j.DailyRollingFileAppender) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66) at org.apache.log4j.Category.callAppenders(Category.java:206) - locked <0x00000007800020a0> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:391) at org.apache.log4j.Category.log(Category.java:856) at org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:
我们定位org.apache.log4j.spi.LocationInfo类的代码如下
String s; // Protect against multiple access to sw. synchronized(sw) { t.printStackTrace(pw); s = sw.toString(); sw.getBuffer().setLength(0); } //System.out.println("s is ["+s+"]."); int ibegin, iend; // Given the current structure of the package, the line // containing "org.apache.log4j.Category." should be printed just // before the caller. // This method of searching may not be fastest but it's safer // than counting the stack depth which is not guaranteed to be // constant across JVM implementations. ibegin = s.lastIndexOf(fqnOfCallingClass);
从上面可以看出在该方法中用了synchronized锁，然后又通过打印堆栈来获取行号。那么肯定会影响到性能的，我们通过看
此时log4j.properties日志文件配置的输出格式为：
%d %-5p %c:%L [%t] - %m%n
很明显就是%l输出行号的问题，那么我们把%l去掉结果会不会好很多呢？
把log4j.properties文件中输出格式改为：
%d %-5p %c [%t] - %m%n
输出格式优化后
再看每秒的并发量如下图
