slf4j-logback-Appender进阶

logback 进阶
基础篇请参考http://wangxinchun.iteye.com/blog/2094761
1、AsyncAppender。
为了提升性能，logback 支持异步的日志记录。

关于异步：本质就是执行不等待，所谓执行就是提交任务。任务执行 1、有结果：一般认为执行完可以回调;2、没有结果，执行完就完事。log的记录就是典型的没有结果的情况，调用方不需要知道执行的最终结果。

实现： logback 是通过 ch.qos.logback.classic.AsyncAppender 来实现异步的log日志记录的。其内部实现是通过保存一个 BlockingQueue<E> blockingQueue; 来缓存 （info,warn,error）的日志消息，然后由一个 Worker worker 线程 从 blockingQueue 中 blockingQueue.take();数据，并输出到   AppenderAttachableImpl<E> aai 中。

关于BlockingQueue的使用 是异步的重点，请参考：
http://wangxinchun.iteye.com/blog/1882960

使用说明：
queueSize 缓存记录的size 非常重要，默认是256，对于并发量较高的系统，队列深度需要根据业务场景进行相应的测试，做出相应的更改，以达到较好的性能。
discardingThreshold：默认情况下，当BlockingQueue还有20%容量，他将丢弃TRACE、DEBUG和INFO级别的event，只保留WARN和ERROR级别的event。为了保持所有的events，设置该值为0。

相关源码：

public class AsyncAppenderBase<E> extends UnsynchronizedAppenderBase<E> implements AppenderAttachable<E> {
  //内部要输出的appender
  AppenderAttachableImpl<E> aai = new AppenderAttachableImpl<E>();
  // log 消息队列
  BlockingQueue<E> blockingQueue;

  /**
   * 默认的消息队列，一般可以稍大一点*/
  public static final int DEFAULT_QUEUE_SIZE = 256;
  int queueSize = DEFAULT_QUEUE_SIZE;
  int appenderCount = 0;

  static final int UNDEFINED = -1;
  int discardingThreshold = UNDEFINED;
   //实际的log 输出线程任务
  Worker worker = new Worker();
  //其他略
}

使用case案例：

    <!-- 循环文件输出（基于时间戳的分文件，是实际项目中用途最广的一种情况） -->
	<appender name="ROLLING_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
	   <file>rooling.log</file>
		<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
			<fileNamePattern>rooling-log.%d{yyyy-MM-dd-HH}.log.gz</fileNamePattern>
			<maxHistory>30</maxHistory>
		</rollingPolicy>
		<encoder>
			<pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n </pattern>
		</encoder>
	</appender>

    <appender name="SYNC_ROLLING_FILE" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="ROLLING_FILE"/>
        <queueSize>1024</queueSize>
		<discardingThreshold>0</discardingThreshold>
    </appender>

	<logger name="com.qunar.logback.LogbackTest" additivity="false"
		level="debug">
		 <!-- <appender-ref ref="SYNC_ROLLING_FILE" />   -->
		<appender-ref ref="ROLLING_FILE" /> 
	</logger>

测试：

@Test
	public void testLogback() throws InterruptedException {
		long l = System.currentTimeMillis();
		for(int i=0;i<30000;i++){
			logger.debug("hello {} ", "world" +i);
			logger.info("hello {} ", "world"+i);
			logger.warn("hello {} ", "world"+i);
			logger.error("hello {} ", "world"+i);
			if(i%1000 == 0){
				Thread.currentThread().sleep(50);
			}
		}
		System.out.println(System.currentTimeMillis() - l);
		Thread.currentThread().sleep(1000);
	}

结论：
同步的耗时：3800 左右
异步的耗时：4500 左右
另外：考虑到实际的生产环境，大多不会把缓存填满，异步的性能优势会更明显。

请注意：如果循环非常快，有可能队列很快就满了，当前线程要等待work线程把数据输出到appender，这样的测试是不能显示异步appender的优势的，所以i%1000==0 进行了短暂的等待。

2、RollingFileAppender
循环文件输出appender，特点：可以根据rollingPolicy 来指定文件名的规则，按照时间或自增id ，保证log输出到由（%d）当前时间指定的特定的文件内，同一个时间规则，有可以根据（%i）来根据文件的大小分多个文件。

对于RollingFileAppender 一般必须要指定 rollingPolicy 和 triggeringPolicy，由于TimeBasedRollingPolicy 实现了TriggeringPolicy 和 RollingPolicy 所以如果rollingPolicy  配置为 TimeBasedRollingPolicy  ，可以不配置triggeringPolicy。

TimeBasedRollingPolicy案例如下：

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="30 seconds">
	<contextName>myAppName</contextName>
	<!-- 命令行输出 -->
	<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
		<encoder>
			<pattern>%d{HH:mm:ss.SSS} %contextName [%thread] %-5level %logger{36}- %msg%n</pattern>
		</encoder>
	</appender>

    <!-- 循环文件输出（基于时间戳的分文件，是实际项目中用途最广的一种情况） -->
	<appender name="ROLLING_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
	    <file>rooling.log</file>
		<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
			<fileNamePattern>rooling-log.%d{yyyy-MM-dd-HH}.%i.log.gz</fileNamePattern>
			<maxHistory>30</maxHistory>
			 <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
		        <maxFileSize>1MB</maxFileSize>
		     </timeBasedFileNamingAndTriggeringPolicy>
		</rollingPolicy>
		<encoder>
			<pattern>%d{HH:mm:ss.SSS} %contextName [%thread] %-5level %logger{36}- %msg%n</pattern>
		</encoder>
	</appender>

	<logger name="com.qunar.logback.LogbackTest" additivity="true"
		level="debug">
		<appender-ref ref="ROLLING_FILE" />
	</logger>

	<root level="INFO">
		<appender-ref ref="STDOUT" />
	</root>
</configuration>

输出的效果如下：


FixedWindowRollingPolicy
固定格式，固定文件大小的rooling策略。

案例如下：

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="30 seconds">
	<contextName>myAppName</contextName>
	<!-- 命令行输出 -->
	<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
		<encoder>
			<pattern>%d{HH:mm:ss.SSS} %contextName [%thread] %-5level %logger{36}- %msg%n</pattern>
		</encoder>
	</appender>

    <!-- 循环文件输出（基于时间戳的分文件，是实际项目中用途最广的一种情况） -->
	<appender name="ROLLING_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
	    <file>test.log</file>
		<rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
	      <fileNamePattern>tests.%i.log.zip</fileNamePattern>
	      <minIndex>1</minIndex>
	      <maxIndex>3</maxIndex>
	    </rollingPolicy>
	    
	     <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
	      <maxFileSize>1MB</maxFileSize>
	    </triggeringPolicy>
	    
		<encoder>
			<pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n </pattern>
		</encoder>
	</appender>

	<logger name="com.qunar.logback.LogbackTest" additivity="false"
		level="debug">
		<appender-ref ref="ROLLING_FILE" />
	</logger>

	<root level="INFO">
		<appender-ref ref="STDOUT" />
	</root>
</configuration>

输出结果：