`
QiaoDuanni
  • 浏览: 136870 次
  • 性别: Icon_minigender_1
  • 来自: 杭州
社区版块
存档分类
最新评论

log4j 与 logback 性能对比

    博客分类:
  • java
阅读更多
代码来自 : logback performance clarification
机器配置
Win XP SP3
双核 Intel(R) Core(TM)2 Duo CPU E7400 @ 2.80GHz
2GB内存
结果:
引用

###################### loop 10w #########################
Log4j direct debug call: 250
Log4j direct warn call: 44381
Log4j tested (isDebugEnabled) debug call: 17
###############################################
###################### loop 100w # perfiles 500KB 2000files#########################
Log4j direct debug call: 250
Log4j direct warn call: 45664
Log4j tested (isDebugEnabled) debug call: 13
###############################################
######################## loop 100w # perfiles 500KB 2000files#######################
Log4j direct debug call: 239
Log4j direct warn call: 62462
Log4j tested (isDebugEnabled) debug call: 13
###############################################
################### loop 1000000 # perfiles 10MB 2000files############################
Log4j direct debug call: 236
Log4j direct warn call: 44482
Log4j tested (isDebugEnabled) debug call: 13
###############################################
################### loop 1000000 # perfiles 100MB 2000files############################
Log4j direct debug call: 240
Log4j direct warn call: 44305
Log4j tested (isDebugEnabled) debug call: 13
###############################################
################### loop 1000000 # perfiles 200MB 2000files############################
Log4j direct debug call: 236
Log4j direct warn call: 45445
Log4j tested (isDebugEnabled) debug call: 13
###############################################

########################### 异步模式 ########################################
################### loop 100000 #ASYNC 10线程 500KB 2000files############################
Log4j direct debug call: 938
Log4j direct warn call: 623017
Log4j tested (isDebugEnabled) debug call: 12
###############################################
################### loop 100000 #ASYNC 10线程 500KB 2000files############################
Log4j direct debug call: 989
Log4j direct warn call: 636342
Log4j tested (isDebugEnabled) debug call: 12
###############################################
################### loop 100000 #ASYNC 10线程 10MB 2000files############################
Log4j direct debug call: 954
Log4j direct warn call: 498409
Log4j tested (isDebugEnabled) debug call: 12
###############################################
################### loop 100000 #ASYNC 10线程 100MB 2000files############################
Log4j direct debug call: 961
Log4j direct warn call: 517658
Log4j tested (isDebugEnabled) debug call: 12
###############################################
################### loop 100000 #ASYNC 10线程 200MB 2000files############################
Log4j direct debug call: 994
Log4j direct warn call: 521485
Log4j tested (isDebugEnabled) debug call: 11
###############################################



##################### loop 10w ##########################
Logback direct debug call: 224
Logback direct warn call: 10649
Logback tested (isDebugEnabled) debug call: 16
Logback tested (isWarnEnabled) warn call: 10754
Logback parametrized debug call: 25
Logback parametrized warn call: 11544
###############################################
###############################################
Logback direct debug call: 205
Logback direct warn call: 10634
Logback tested (isDebugEnabled) debug call: 12
Logback tested (isWarnEnabled) warn call: 10886
Logback parametrized debug call: 20
Logback parametrized warn call: 11521
###############################################
################## loop 1000000 # perfiles 500KB and zip#############################
Logback direct debug call: 214
Logback direct warn call: 22342
Logback tested (isDebugEnabled) debug call: 11
Logback tested (isWarnEnabled) warn call: 11079
Logback parametrized debug call: 22
Logback parametrized warn call: 11959
###############################################
################## loop 1000000 # perfiles 500KB and zip#############################
Logback direct debug call: 203
Logback direct warn call: 10297
Logback tested (isDebugEnabled) debug call: 11
Logback tested (isWarnEnabled) warn call: 10585
Logback parametrized debug call: 20
Logback parametrized warn call: 10884
###############################################
################## loop 1000000 # perfiles 200MB and zip#############################
Logback direct debug call: 206
Logback direct warn call: 8472
Logback tested (isDebugEnabled) debug call: 12
Logback tested (isWarnEnabled) warn call: 8600
Logback parametrized debug call: 21
Logback parametrized warn call: 8707
###############################################
################## loop 1000000 # perfiles 100MB and zip#############################
Logback direct debug call: 395
Logback direct warn call: 40629
Logback tested (isDebugEnabled) debug call: 11
Logback tested (isWarnEnabled) warn call: 40417
Logback parametrized debug call: 20
Logback parametrized warn call: 40687
Count Times(ms) : 122156
###############################################
################## loop 1000000 # perfiles 100MB and zip#############################
Logback direct debug call: 236
Logback direct warn call: 8489
Logback tested (isDebugEnabled) debug call: 11
Logback tested (isWarnEnabled) warn call: 8535
Logback parametrized debug call: 21
Logback parametrized warn call: 9042
###############################################
################## loop 1000000 # perfiles 50MB and zip#############################
Logback direct debug call: 217
Logback direct warn call: 8508
Logback tested (isDebugEnabled) debug call: 11
Logback tested (isWarnEnabled) warn call: 8695
Logback parametrized debug call: 20
Logback parametrized warn call: 8757
###############################################
################## loop 1000000 # perfiles 10MB and zip#############################
Logback direct debug call: 208
Logback direct warn call: 8499
Logback tested (isDebugEnabled) debug call: 12
Logback tested (isWarnEnabled) warn call: 8578
Logback parametrized debug call: 22
Logback parametrized warn call: 8741
###############################################
################## loop 100000  # jdbc(c3p0) #############################
Logback direct debug call: 355
Logback direct warn call: 3937399
Logback tested (isDebugEnabled) debug call: 27
Logback tested (isWarnEnabled) warn call: 4040561
Logback parametrized debug call: 40
Logback parametrized warn call: 4004411
###############################################
################## loop 2000000 # 1 Main Thread 100MB #per LogSize 286 Byte#############################
Logback direct debug call: 406
Logback direct warn call: 40168
Logback tested (isDebugEnabled) debug call: 11
Logback tested (isWarnEnabled) warn call: 40212
Logback parametrized debug call: 20
Logback parametrized warn call: 40562
Count Times(ms) : 242765
###############################################
################## loop 1000000 # 1 Main Thread 100MB #per LogSize 286 Byte#############################
Logback direct debug call: 389
Logback direct warn call: 39958
Logback tested (isDebugEnabled) debug call: 11
Logback tested (isWarnEnabled) warn call: 40440
Logback parametrized debug call: 20
Logback parametrized warn call: 40335
Count Times(ms) : 121156
###############################################
################## loop 1000000 # socket 1 client 1 Main Thread 100MB #per LogSize 286 Byte#############################
Logback direct debug call: 401
Logback direct warn call: 117924
Logback tested (isDebugEnabled) debug call: 11
Logback tested (isWarnEnabled) warn call: 118562
Logback parametrized debug call: 19
Logback parametrized warn call: 128202
Count Times(ms) : 365110
###############################################
################## loop 100000 # socket 1 client 1 Main Thread 100MB #per LogSize 286 Byte#############################
Logback direct debug call: 148301
Logback direct warn call: 152806
Logback tested (isDebugEnabled) debug call: 150971
Logback tested (isWarnEnabled) warn call: 141062
Logback parametrized debug call: 158658
Logback parametrized warn call: 153140
Count Times(ms) : 90500
###############################################
################## loop 1000000 # socket 1 client 1 Main Thread 100MB #per LogSize 286 Byte#############################
Logback direct debug call: 388
Logback direct warn call: 144331
Logback tested (isDebugEnabled) debug call: 10
Logback tested (isWarnEnabled) warn call: 96334
Logback parametrized debug call: 20
Logback parametrized warn call: 92826
Count Times(ms) : 333907
###############################################
################## loop 1000000 # socket 1 client 1 Main Thread 100MB #per LogSize 286 Byte#############################
Logback direct debug call: 392
Logback direct warn call: 166776
Logback tested (isDebugEnabled) debug call: 11
Logback tested (isWarnEnabled) warn call: 216869
Logback parametrized debug call: 141
Logback parametrized warn call: 156749
Count Times(ms) : 540969
###############################################


################## loop 100000 # 10thread 20queueSize 500KB and zip #per LogSize 286 Byte#############################
Logback direct debug call: 885
Logback direct warn call: 451863
Logback tested (isDebugEnabled) debug call: 9
Logback tested (isWarnEnabled) warn call: 451750
Logback parametrized debug call: 21
Logback parametrized warn call: 449805
###############################################
################## loop 100000 # 10 Thread 20 QueueSize 10MB and zip #per LogSize 286 Byte#############################
Logback direct debug call: 918
Logback direct warn call: 450027
Logback tested (isDebugEnabled) debug call: 9
Logback tested (isWarnEnabled) warn call: 452299
Logback parametrized debug call: 22
Logback parametrized warn call: 437268
###############################################
################## loop 100000 # 10 Thread 20 QueueSize 100MB and zip #per LogSize 286 Byte#############################
Logback direct debug call: 808
Logback direct warn call: 445219
Logback tested (isDebugEnabled) debug call: 10
Logback tested (isWarnEnabled) warn call: 449316
Logback parametrized debug call: 20
Logback parametrized warn call: 431124
###############################################
################## loop 100000 # 10 Thread 20 QueueSize 200MB and zip #per LogSize 286 Byte#############################
Logback direct debug call: 851
Logback direct warn call: 445867
Logback tested (isDebugEnabled) debug call: 10
Logback tested (isWarnEnabled) warn call: 450838
Logback parametrized debug call: 21
Logback parametrized warn call: 440028
###############################################
################## loop 100000 # 50 Thread 50 QueueSize 100MB and zip #per LogSize 286 Byte#############################
Logback direct debug call: 8719
Logback direct warn call: 2358846
Logback tested (isDebugEnabled) debug call: 10
Logback tested (isWarnEnabled) warn call: 2346821
Logback parametrized debug call: 20
Logback parametrized warn call: 2329942
###############################################
################## loop 100000 # 4 Thread 20 QueueSize 100MB and zip #per LogSize 286 Byte#############################
Logback direct debug call: 1299
Logback direct warn call: 195412
Logback tested (isDebugEnabled) debug call: 14
Logback tested (isWarnEnabled) warn call: 194969
Logback parametrized debug call: 24
Logback parametrized warn call: 192029
###############################################
################## loop 100000 # 3 Thread 20 QueueSize 100MB and zip #per LogSize 286 Byte#############################
Logback direct debug call: 915
Logback direct warn call: 145027
Logback tested (isDebugEnabled) debug call: 11
Logback tested (isWarnEnabled) warn call: 140793
Logback parametrized debug call: 21
Logback parametrized warn call: 143145
###############################################
################## loop 100000 # 2 Thread 20 QueueSize 100MB and zip  #per LogSize 286 Byte#############################
Logback direct debug call: 961
Logback direct warn call: 95941
Logback tested (isDebugEnabled) debug call: 10
Logback tested (isWarnEnabled) warn call: 96473
Logback parametrized debug call: 20
Logback parametrized warn call: 96345
###############################################
################## loop 100000 # 1 Thread 20 QueueSize 100MB and zip  #per LogSize 286 Byte#############################
Logback direct debug call: 414
Logback direct warn call: 44408
Logback tested (isDebugEnabled) debug call: 9
Logback tested (isWarnEnabled) warn call: 44709
Logback parametrized debug call: 18
Logback parametrized warn call: 45287
###############################################
################## loop 100000 # 1 Thread 20 QueueSize 100MB #per LogSize 286 Byte#############################
Logback direct debug call: 403
Logback direct warn call: 43233
Logback tested (isDebugEnabled) debug call: 10
Logback tested (isWarnEnabled) warn call: 43490
Logback parametrized debug call: 19
Logback parametrized warn call: 43935
Count Times(ms) : 270000
###############################################
################## loop 100000 # 1 Thread 20 QueueSize 100MB #per LogSize 286 Byte#############################
Logback direct debug call: 410
Logback direct warn call: 43172
Logback tested (isDebugEnabled) debug call: 9
Logback tested (isWarnEnabled) warn call: 43314
Logback parametrized debug call: 19
Logback parametrized warn call: 43751
Count Times(ms) : 283812
###############################################
################## loop 100000 # 2 Thread 20 QueueSize 100MB #per LogSize 286 Byte#############################
Logback direct debug call: 511
Logback direct warn call: 92970
Logback tested (isDebugEnabled) debug call: 12
Logback tested (isWarnEnabled) warn call: 90352
Logback parametrized debug call: 20
Logback parametrized warn call: 92044
Count Times(ms) : 304656
###############################################
################## loop 100000 # 3 Thread 20 QueueSize 100MB #per LogSize 286 Byte#############################
Logback direct debug call: 619
Logback direct warn call: 136300
Logback tested (isDebugEnabled) debug call: 10
Logback tested (isWarnEnabled) warn call: 146003
Logback parametrized debug call: 20
Logback parametrized warn call: 109449
Count Times(ms) : 294078
###############################################
################## loop 100000 # 4 Thread 20 QueueSize 100MB #per LogSize 286 Byte#############################
Logback direct debug call: 702
Logback direct warn call: 171259
Logback tested (isDebugEnabled) debug call: 11
Logback tested (isWarnEnabled) warn call: 178437
Logback parametrized debug call: 21
Logback parametrized warn call: 187121
Count Times(ms) : 293609
###############################################


log4j测试代码
/**
 * $Id$
 */
package perfTest.ch.qos.logback;

import org.apache.log4j.Logger;
import org.apache.log4j.xml.DOMConfigurator;

/**
 * @author Last changed by: $Author$
 * @version $Revision$ $Date$
 */
public class PerformanceLog4j {
	static Logger log4jlogger = Logger.getLogger(PerformanceLog4j.class);

	// How many times should we try to log:
	static int loop = 1000000;

	public static void main(String[] args) throws InterruptedException {
		initConfig();

		// Let's run once for Just In Time compiler
		log4jDirectDebugCall();
		log4jDirectWarnCall();
		log4jTestedDebugCall();

		// let's run the tests and display the results:
		long result1 = log4jDirectDebugCall();
		long result2 = log4jDirectWarnCall();
		long result3 = log4jTestedDebugCall();

		System.out.println("################### loop " + loop + " ############################");
		System.out.println("Log4j direct debug call: " + result1);
		System.out.println("Log4j direct warn call: " + result2);
		System.out.println("Log4j tested (isDebugEnabled) debug call: " + result3);
		System.out.println("###############################################");
	}

	private static long log4jDirectDebugCall() {
		Integer j = new Integer(1);
		long start = System.nanoTime();
		for (int i = 0; i < loop; i++) {
			log4jlogger.debug("SEE IF THIS IS LOGGED log4jDirectDebugCall() " + j + ".");
		}
		return (System.nanoTime() - start) / loop;
	}

	private static long log4jDirectWarnCall() {
		Integer j = new Integer(2);
		long start = System.nanoTime();
		for (int i = 0; i < loop; i++) {
			log4jlogger.warn("SEE IF THIS IS LOGGED  log4jDirectWarnCall()" + j + ".");
		}
		return (System.nanoTime() - start) / loop;
	}

	private static long log4jTestedDebugCall() {
		Integer j = new Integer(3);
		long start = System.nanoTime();
		for (int i = 0; i < loop; i++) {
			if (log4jlogger.isDebugEnabled()) {
				log4jlogger.debug("SEE IF THIS IS LOGGED log4jTestedDebugCall() " + j + ".");
			}
		}
		return (System.nanoTime() - start) / loop;
	}

	private static void initConfig() {
		DOMConfigurator.configure("src/main/resource/log4j.xml");

		// create the loggers
		org.apache.log4j.Logger.getLogger("perfTest");
		org.apache.log4j.Logger.getLogger("perfTest.ch");
		org.apache.log4j.Logger.getLogger("perfTest.ch.qos");
		org.apache.log4j.Logger.getLogger("perfTest.ch.qos.logback");
	}
}


<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j='http://jakarta.apache.org/log4j/'>

<!--	<appender name="ASYNC" class="org.apache.log4j.AsyncAppender">-->
<!--		<appender-ref ref="STDOUT" />-->
<!--	</appender>-->

	<appender name="STDOUT" class="org.apache.log4j.ConsoleAppender">
		<layout class="org.apache.log4j.PatternLayout">
			<param name="ConversionPattern" value="%d (%t) [%24F:%-3L:%-5p]%x %m%n" />
		</layout>
	</appender>
	
	<appender name="FILE" class="org.apache.log4j.RollingFileAppender">
		<param name="File" value="logs/log4j-test.log" />
		<param name="BufferSize" value="8129" />
		<param name="Append" value="true" />
		<param name="MaxFileSize" value="200MB"/>
		<param name="MaxBackupIndex" value="2000"/>
		<layout class="org.apache.log4j.PatternLayout">
			<param name="ConversionPattern" value="%d (%t) [%24F:%-3L:%-5p]%x %m%n" />
		</layout>
	</appender>
	
	
	<root>
		<priority value="INFO" />
<!--		<appender-ref ref="STDOUT" />-->
		 <appender-ref ref="FILE"/> 
	</root>

</log4j:configuration>


logback测试代码
/**
 * $Id$
 */
package perfTest.ch.qos.logback;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.joran.JoranConfigurator;
import ch.qos.logback.core.joran.spi.JoranException;
import ch.qos.logback.core.util.StatusPrinter;

/**
 * @author Last changed by: $Author$
 * @version $Revision$ $Date$
 */
public class PerformanceLogback {
	static Logger logbacklogger = LoggerFactory.getLogger(PerformanceLogback.class);

	// How many times should we try to log:
	static int loop = 1000000;

	public static void main(String[] args) throws InterruptedException {
		// initConfig();

		// Let's run once for Just In Time compiler
		logbackDirectDebugCall();
		logbackDirectWarnCall();
		logbackTestedDebugCall();
		logbackTestedWarnCall();
		logbackParametrizedDebugCall();
		logbackParametrizedWarnCall();

		// let's run the tests and display the results:
		long result4 = logbackDirectDebugCall();
		long result5 = logbackDirectWarnCall();
		long result6 = logbackTestedDebugCall();
		long result7 = logbackTestedWarnCall();
		long result8 = logbackParametrizedDebugCall();
		long result9 = logbackParametrizedWarnCall();

		System.out.println("################## loop " + loop + " #############################");
		System.out.println("Logback direct debug call: " + result4);
		System.out.println("Logback direct warn call: " + result5);
		System.out.println("Logback tested (isDebugEnabled) debug call: " + result6);
		System.out.println("Logback tested (isWarnEnabled) warn call: " + result7);
		System.out.println("Logback parametrized debug call: " + result8);
		System.out.println("Logback parametrized warn call: " + result9);
		System.out.println("###############################################");
	}

	private static long logbackDirectDebugCall() {
		Integer j = new Integer(5);
		long start = System.nanoTime();
		for (int i = 0; i < loop; i++) {
			logbacklogger.debug("SEE IF THIS IS LOGGED " + j + ".");
		}
		return (System.nanoTime() - start) / loop;
	}

	private static long logbackDirectWarnCall() {
		Integer j = new Integer(6);
		long start = System.nanoTime();
		for (int i = 0; i < loop; i++) {
			logbacklogger.warn("SEE IF THIS IS LOGGED logbackDirectWarnCall()" + j + ".");
		}
		return (System.nanoTime() - start) / loop;
	}

	private static long logbackTestedDebugCall() {
		Integer j = new Integer(7);
		long start = System.nanoTime();
		for (int i = 0; i < loop; i++) {
			if (logbacklogger.isDebugEnabled())
				logbacklogger.debug("SEE IF THIS IS LOGGED " + j + ".");
		}
		return (System.nanoTime() - start) / loop;
	}

	private static long logbackTestedWarnCall() {
		Integer j = new Integer(8);
		long start = System.nanoTime();
		for (int i = 0; i < loop; i++) {
			if (logbacklogger.isWarnEnabled())
				logbacklogger.warn("SEE IF THIS IS LOGGED logbackTestedWarnCall()" + j + ".");
		}
		long end = System.nanoTime();
		long result = (end - start) / loop;
		System.out.println("start = " + start + "end = " + end + "result = " + result);
		return result;
	}

	private static long logbackParametrizedDebugCall() {
		Integer j = new Integer(9);
		long start = System.nanoTime();
		for (int i = 0; i < loop; i++) {
			logbacklogger.debug("SEE IF THIS IS LOGGED {}.", j);
		}
		return (System.nanoTime() - start) / loop;
	}

	private static long logbackParametrizedWarnCall() {
		Integer j = new Integer(10);
		long start = System.nanoTime();
		for (int i = 0; i < loop; i++) {
			logbacklogger.warn("SEE IF THIS IS LOGGED logbackParametrizedWarnCall() {}.", j);
		}
		long end = System.nanoTime();
		long result = (end - start) / loop;
		System.out.println("start = " + start + "end = " + end + "result = " + result);
		return result;
	}

	private static void initConfig() {
		// assume SLF4J is bound to logback in the current environment
		LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();

		try {
			JoranConfigurator configurator = new JoranConfigurator();
			configurator.setContext(lc);
			// the context was probably already configured by default configuration
			// rules
			lc.reset();
			configurator.doConfigure("src/main/resource/logback.xml");
		} catch (JoranException je) {
			// StatusPrinter will handle this
		}
		StatusPrinter.printInCaseOfErrorsOrWarnings(lc);

		// create the loggers
		LoggerFactory.getLogger("perfTest");
		LoggerFactory.getLogger("perfTest.ch");
		LoggerFactory.getLogger("perfTest.ch.qos");
		LoggerFactory.getLogger("perfTest.ch.qos.logback");
	}
}


<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
	<property file="src/main/resource/jdbc.properties" />

	<appender name="DB" class="ch.qos.logback.classic.db.DBAppender">
		<connectionSource class="ch.qos.logback.core.db.DataSourceConnectionSource">
			<dataSource class="com.mchange.v2.c3p0.ComboPooledDataSource">
				<driverClass>${jdbc.driver.class}</driverClass>
				<jdbcUrl>${jdbc.url}</jdbcUrl>
				<!--				<serverName>${serverName}</serverName>-->
				<!--         <databaseName>${databaseName}</databaseName>-->
				<user>${jdbc.username}</user>
				<password>${jdbc.password}</password>
				<param name="minPoolSize" value="30" />
				<param name="maxPoolSize" value="60" />
				<param name="initialPoolSize" value="30" />
				<param name="acquireIncrement" value="3" />
				<param name="acquireRetryAttempts" value="30" />
				<param name="acquireRetryDelay" value="1000" />
				<param name="autoCommitOnClose" value="false" />
				<param name="breakAfterAcquireFailure" value="false" />
				<param name="checkoutTimeout" value="0" />
				<param name="maxIdleTime" value="60" />
				<param name="maxStatements" value="100" />
			</dataSource>

		</connectionSource>
	</appender>
	<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
		<file>logs/logback-test.log</file>
		<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
			<!-- rollover daily -->
			<fileNamePattern>logs/logback-%d{yyyy-MM-dd}.%i.zip</fileNamePattern>
			<timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
				<!-- or whenever the file size reaches 100MB -->
				<maxFileSize>10MB</maxFileSize>
			</timeBasedFileNamingAndTriggeringPolicy>
		</rollingPolicy>
		<encoder>
			<pattern>%date{ISO8601} [%thread] [%24file:%M:%-3line:%-5level] - %msg%n</pattern>
		</encoder>
	</appender>

	<root level="INFO">
<!--		<appender-ref ref="DB" />-->
		<appender-ref ref="FILE" />
	</root>
</configuration>

jdbc.properties
# mysql config
jdbc.driver.class=com.mysql.jdbc.Driver
jdbc.url=jdbc:mysql://localhost/logs?autoReconnect=true&useUnicode=true&characterEncoding=utf8
jdbc.username=root
jdbc.password=root


10线程模式
/**
 * $Id$
 */
package perfTest.ch.qos.logback;

import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ConcurrentMap;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;

import org.apache.log4j.Logger;
import org.apache.log4j.xml.DOMConfigurator;

/**
 * @author Last changed by: $Author$
 * @version $Revision$ $Date$
 */
public class PerformanceLog4j {

	// How many times should we try to log:
	static int loop = 100000;

	static ConcurrentMap<Integer, Long> result = new ConcurrentHashMap<Integer, Long>();

	static int RESULT_1 = 1;
	static int RESULT_2 = 2;
	static int RESULT_3 = 3;
	static int countThread = 20;

	public PerformanceLog4j() {

	}

	public void start() {
		initConfig();
		result.put(RESULT_1, 0L);
		result.put(RESULT_2, 0L);
		result.put(RESULT_3, 0L);
		int countT = countThread;
		ExecutorService executor = Executors.newFixedThreadPool(10);

		for (int i = 0; i < countThread; i++) {
			executor.execute(new Log4jRun());
		}

		while (countThread > 0) {
			try {
				Thread.sleep(10000);
			} catch (InterruptedException e) {
				e.printStackTrace();
			}
		}
		executor.shutdown();

		System.out.println("################### loop " + loop + " #ASYNC ############################");
		System.out.println("Log4j direct debug call: " + result.get(RESULT_1) / countT);
		System.out.println("Log4j direct warn call: " + result.get(RESULT_2) / countT);
		System.out.println("Log4j tested (isDebugEnabled) debug call: " + result.get(RESULT_3) / countT);
		System.out.println("###############################################");

	}

	public static void main(String[] args) throws InterruptedException {
		new PerformanceLog4j().start();
	}

	private static void initConfig() {
		DOMConfigurator.configure("src/main/resource/log4j.xml");

		// create the loggers
		org.apache.log4j.Logger.getLogger("perfTest");
		org.apache.log4j.Logger.getLogger("perfTest.ch");
		org.apache.log4j.Logger.getLogger("perfTest.ch.qos");
		org.apache.log4j.Logger.getLogger("perfTest.ch.qos.logback");
	}

	static class Log4jRun implements Runnable {
		static Logger log4jlogger = Logger.getLogger(Log4jRun.class);

		static {
			// Let's run once for Just In Time compiler
			log4jDirectDebugCall();
			log4jDirectWarnCall();
			log4jTestedDebugCall();
		}

		public Log4jRun() {

		}

		/*
		 * (non-Javadoc)
		 * @see java.lang.Runnable#run()
		 */
		@Override
		public void run() {
			System.out.println("start " + Thread.currentThread());
			// let's run the tests and display the results:
			long result1 = log4jDirectDebugCall();
			long result2 = log4jDirectWarnCall();
			long result3 = log4jTestedDebugCall();
			synchronized (result) {
				result.put(RESULT_1, result.get(RESULT_1) + result1);
				result.put(RESULT_2, result.get(RESULT_2) + result2);
				result.put(RESULT_3, result.get(RESULT_3) + result3);
			}
			countThread--;
			System.out.println("count " + countThread + " end " + Thread.currentThread());
		}

		private static long log4jDirectDebugCall() {
			Integer j = new Integer(1);
			long start = System.nanoTime();
			for (int i = 0; i < loop; i++) {
				log4jlogger.debug("SEE IF THIS IS LOGGED log4jDirectDebugCall() " + j + ".");
			}
			return (System.nanoTime() - start) / loop;
		}

		private static long log4jDirectWarnCall() {
			Integer j = new Integer(2);
			long start = System.nanoTime();
			for (int i = 0; i < loop; i++) {
				log4jlogger.warn("SEE IF THIS IS LOGGED  log4jDirectWarnCall()" + j + ".");
			}
			return (System.nanoTime() - start) / loop;
		}

		private static long log4jTestedDebugCall() {
			Integer j = new Integer(3);
			long start = System.nanoTime();
			for (int i = 0; i < loop; i++) {
				if (log4jlogger.isDebugEnabled()) {
					log4jlogger.debug("SEE IF THIS IS LOGGED log4jTestedDebugCall() " + j + ".");
				}
			}
			return (System.nanoTime() - start) / loop;
		}

	}
}


/**
 * $Id$
 */
package perfTest.ch.qos.logback;

import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ConcurrentMap;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
 * @author Last changed by: $Author$
 * @version $Revision$ $Date$
 */
public class PerformanceLogback {

	// How many times should we try to log:
	static int loop = 100000;

	static ConcurrentMap<Integer, Long> result = new ConcurrentHashMap<Integer, Long>();

	static int RESULT_4 = 1;
	static int RESULT_5 = 2;
	static int RESULT_6 = 3;
	static int RESULT_7 = 4;
	static int RESULT_8 = 5;
	static int RESULT_9 = 6;
	static int countThread = 20;

	public PerformanceLogback() {

	}

	public void start() {
		result.put(RESULT_4, 0L);
		result.put(RESULT_5, 0L);
		result.put(RESULT_6, 0L);
		result.put(RESULT_7, 0L);
		result.put(RESULT_8, 0L);
		result.put(RESULT_9, 0L);

		int countT = countThread;
		ExecutorService executor = Executors.newFixedThreadPool(10);

		for (int i = 0; i < countThread; i++) {
			executor.execute(new LogbackRun());
		}

		while (countThread > 0) {
			try {
				Thread.sleep(10000);
			} catch (InterruptedException e) {
				e.printStackTrace();
			}
		}
		executor.shutdown();

		System.out.println("################## loop " + loop + " #############################");
		System.out.println("Logback direct debug call: " + result.get(RESULT_4) / countT);
		System.out.println("Logback direct warn call: " + result.get(RESULT_5) / countT);
		System.out.println("Logback tested (isDebugEnabled) debug call: " + result.get(RESULT_6) / countT);
		System.out.println("Logback tested (isWarnEnabled) warn call: " + result.get(RESULT_7) / countT);
		System.out.println("Logback parametrized debug call: " + result.get(RESULT_8) / countT);
		System.out.println("Logback parametrized warn call: " + result.get(RESULT_9) / countT);
		System.out.println("###############################################");
	}

	public static void main(String[] args) throws InterruptedException {
		new PerformanceLogback().start();
	}

	static class LogbackRun implements Runnable {
		static Logger logbacklogger = LoggerFactory.getLogger(LogbackRun.class);

		static {
			// Let's run once for Just In Time compiler
			logbackDirectDebugCall();
			logbackDirectWarnCall();
			logbackTestedDebugCall();
			logbackTestedWarnCall();
			logbackParametrizedDebugCall();
			logbackParametrizedWarnCall();
		}
		/*
		 * (non-Javadoc)
		 * @see java.lang.Runnable#run()
		 */
		@Override
		public void run() {
			System.out.println("start " + Thread.currentThread());
			// let's run the tests and display the results:
			long result4 = logbackDirectDebugCall();
			long result5 = logbackDirectWarnCall();
			long result6 = logbackTestedDebugCall();
			long result7 = logbackTestedWarnCall();
			long result8 = logbackParametrizedDebugCall();
			long result9 = logbackParametrizedWarnCall();
			synchronized (result) {
				result.put(RESULT_4, result.get(RESULT_4) + result4);
				result.put(RESULT_5, result.get(RESULT_5) + result5);
				result.put(RESULT_6, result.get(RESULT_6) + result6);
				result.put(RESULT_7, result.get(RESULT_7) + result7);
				result.put(RESULT_8, result.get(RESULT_8) + result8);
				result.put(RESULT_9, result.get(RESULT_9) + result9);
			}
			countThread--;
			System.out.println("count " + countThread + " end " + Thread.currentThread());

		}

		private static long logbackDirectDebugCall() {
			Integer j = new Integer(5);
			long start = System.nanoTime();
			for (int i = 0; i < loop; i++) {
				logbacklogger.debug("SEE IF THIS IS LOGGED " + j + ".");
			}
			return (System.nanoTime() - start) / loop;
		}

		private static long logbackDirectWarnCall() {
			Integer j = new Integer(6);
			long start = System.nanoTime();
			for (int i = 0; i < loop; i++) {
				logbacklogger.warn("SEE IF THIS IS LOGGED logbackDirectWarnCall()" + j + ".");
			}
			return (System.nanoTime() - start) / loop;
		}

		private static long logbackTestedDebugCall() {
			Integer j = new Integer(7);
			long start = System.nanoTime();
			for (int i = 0; i < loop; i++) {
				if (logbacklogger.isDebugEnabled())
					logbacklogger.debug("SEE IF THIS IS LOGGED " + j + ".");
			}
			return (System.nanoTime() - start) / loop;
		}

		private static long logbackTestedWarnCall() {
			Integer j = new Integer(8);
			long start = System.nanoTime();
			for (int i = 0; i < loop; i++) {
				if (logbacklogger.isWarnEnabled())
					logbacklogger.warn("SEE IF THIS IS LOGGED logbackTestedWarnCall()" + j + ".");
			}
			long end = System.nanoTime();
			long result = (end - start) / loop;
			// System.out.println("start = " + start + "end = " + end + "result = " + result);
			return result;
		}

		private static long logbackParametrizedDebugCall() {
			Integer j = new Integer(9);
			long start = System.nanoTime();
			for (int i = 0; i < loop; i++) {
				logbacklogger.debug("SEE IF THIS IS LOGGED {}.", j);
			}
			return (System.nanoTime() - start) / loop;
		}

		private static long logbackParametrizedWarnCall() {
			Integer j = new Integer(10);
			long start = System.nanoTime();
			for (int i = 0; i < loop; i++) {
				logbacklogger.warn("SEE IF THIS IS LOGGED logbackParametrizedWarnCall() {}.", j);
			}
			long end = System.nanoTime();
			long result = (end - start) / loop;
			// System.out.println("start = " + start + "end = " + end + "result = " + result);
			return result;
		}
	}
}

分享到:
评论

相关推荐

    slf4j+logback 于log4j+commons-logging大PK

    今天我们将聚焦两个流行的日志框架——SLF4J(Simple Logging Facade for Java)和Logback,以及它们与Log4j和Commons-Logging的对比。 SLF4J是一个接口层的日志框架,它提供一个统一的API,允许用户在运行时插入...

    Log4j2简介及与Log4j效率对比

    ### Log4j2与Log4j效率对比 #### 测试环境与方法 为了准确评估Log4j2与Log4j之间的性能差异,通常会采用一套标准的效率测试程序。这类程序会模拟大量日志记录操作,并比较两种日志框架在处理相同负载时的性能表现...

    log4j简述(架构、用法等)

    - **与 Logback 的比较**:Logback 作为 Log4j 的一个分支,由 Log4j 的原始作者 Ceki Gülcü 创建。Logback 在设计上更简洁、性能更优,但 Log4j 在社区支持方面仍然具有优势。 - **与 SLF4J 的关系**:SLF4J...

    log4j配置详解与使用方法说明

    ### 五、Log4j与其他日志框架比较 Log4j的替代品有Logback、SLF4J(Simple Logging Facade for Java)等。SLF4J 提供了一个抽象层,允许在运行时绑定不同的日志实现,如Logback(SLF4J的推荐实现)和Log4j。Logback...

    log4j-1.2.16.jar与slf4j-api-1.6.1.jar加个转换包和log4j.properties示例

    通过SLF4J,开发者可以轻松地切换不同的底层日志框架,如Logback或Log4j。 **转换包**: 由于Log4j和SLF4J是两个独立的日志框架,它们之间通常需要一个适配器或转换包来实现兼容。在这种情况下,转换包可能是指`slf...

    Log4j api 下载

    - Logback:由SLF4J作者开发的日志框架,性能优于Log4j,但API不完全兼容。 总的来说,Log4j 提供了一套强大且可定制的日志解决方案,通过下载和正确配置,开发者可以在各种Java应用中充分利用其功能。利用提供的...

    Log4j教程

    **四、Log4j与其他日志框架的比较** Log4j在Java日志领域有很高的市场份额,但它并非唯一的选择。其他常见的日志框架包括Logback(由Log4j的作者设计的替代品)和Java Util Logging (JUL)。Log4j因其丰富的功能集、...

    slf4j+log4j2配置使用

    在实际应用中,Log4j2与其它日志框架(如Logback等)的性能对比也非常重要。在使用SLF4J配合Log4j2时,需要关注不同框架在日志记录时的性能差异,并根据具体情况选择最合适的日志框架。 ### 总结 在Java应用中,...

    Log4j的相关jar包和配置文件

    - Logback:由SLF4J的作者设计,性能优于Log4j,且与SLF4J紧密集成。 7. **日志监控与分析** - 使用工具如ELK Stack(Elasticsearch, Logstash, Kibana)或Graylog收集、分析和展示日志,有助于故障排查和性能...

    log4j手册reference文档

    - **与其他日志框架的对比:** 如logback、SLF4J等,虽然这些框架之间在功能上有一定的相似性,但每种框架都有自己独特的优势和适用场景。 #### 八、总结 Log4j作为一个成熟的日志框架,不仅提供了强大的日志管理...

    Log4j工程官方源码

    - Logback是Log4j的后继者,由同一位作者设计,提供了更好的性能和更多特性。两者在功能上类似,但Logback更新更活跃,社区支持也更为丰富。 了解并熟练使用Log4j,能帮助开发者更好地管理和分析应用程序的运行...

    log4j日志组件

    ### 五、Log4j与其他日志框架的对比 虽然Log4j功能强大,但在现代项目中,也有其他日志框架如Logback和SLF4J(Simple Logging Facade for Java)逐渐流行起来。SLF4J是一个抽象层,允许用户在运行时选择不同的日志...

    log4j学习

    描述部分虽然为空,但通常在学习Log4j时,我们会涉及它的基本概念、配置、使用方法以及与其他日志框架(如logback、java.util.logging)的对比。 **Log4j基础知识** Log4j是Apache软件基金会开发的一个开源项目,...

    log4j-1.2.17.jar

    相比Logback、SLF4J等较新的日志框架,Log4j 1.2.17可能在性能和API设计上稍显不足,但在兼容性和社区支持方面仍有优势。 总结,Log4j-1.2.17.jar作为经典的日志工具,它的强大功能和灵活性使其在Java开发中占据了...

    log4j.rar java写LOG日志的驱动

    **四、Log4j与其他日志框架的对比** 虽然Log4j在日志处理方面表现出色,但随着技术的发展,其他框架如Logback、SLF4J(Simple Logging Facade for Java)也逐渐受到关注。SLF4J作为一个日志门面,提供了统一的API,...

    这是一个log4j的压缩包,直接可以用的。。。

    - **Logback**:由Log4j的主要作者设计,被认为在性能上优于Log4j,并且包含了一些新的特性。 - **SLF4J**:Simple Logging Facade for Java,提供一个通用的日志API,可以和多种日志实现(包括Log4j)配合使用。 ...

    log4j简单例子

    **Log4j与Logback的对比** 虽然Log4j非常流行,但后来出现了Logback作为其替代品,因为Logback在性能和功能上都有所改进。然而,由于Log4j的广泛使用和成熟的生态系统,许多项目仍然继续使用它。 总结来说,“log4...

    apache-log4j

    - Logback:由Log4j的主要开发者设计,比Log4j更快且更轻量级,提供了类似的功能。 - SLF4J(Simple Logging Facade for Java):一个日志抽象层,允许在运行时绑定不同的日志实现,包括Log4j。 7. **日志的最佳...

    log4j从入门到详解

    最后,教程可能还会讨论log4j与其他日志框架(如logback、slf4j)的对比,以及如何在实际项目中选择合适的日志解决方案。在实际开发中,了解这些框架的优缺点和兼容性,可以帮助我们做出更明智的决策。 通过《log4j...

    log4j入门、详解

    6. **Log4j与其他日志框架的比较** 虽然Log4j曾是Java日志领域的首选,但随着Java社区的发展,其他框架如Logback和SLF4J也逐渐流行起来。Logback由Log4j的作者设计,具有更高的性能和灵活性。SLF4J(Simple Logging...

Global site tag (gtag.js) - Google Analytics