Logback的深度使用经验和最佳实践

首先，日志的记录方案，在另一篇文章中单独说明：

http://blog.zollty.com/b/archive/plan-for-java-project-log.html

在该文章中，说明了Logback的下面5个功能：

1、使用logback的环境变量定义和读取功能；

2、在logback启动之前，继承ch.qos.logback.core.status.OnConsoleStatusListener，初始化变量的值；

3、使用logback的 if-then 条件语法；

4、使用<property file="xxx" />和<property resource="xxx" />加载key-value配置

5、使用<include resource="xxx"/>切分配置文件再引入。

 

其他基础的用法，比如 定时扫描配置，日志文件压缩，异步打印日志等功能，见下面的配置及注释：

<?xml version="1.0" encoding="UTF-8"?> <configuration scan="true" scanPeriod="60 seconds" debug="false">       <statusListener class="cn.zollty.commons.logbackext.InitConfigOnConsoleStatusListener" />       <!-- 部署的环境类型：dev、test、product -->   <property name="DEPLOY_ENV" value="${deploy.env:-dev}" />       <!-- 日志路径，这里是相对路径，web项目eclipse下会输出到当前目录./logs/下，如果部署到linux上的tomcat下，会输出到tomcat/logs/目录 下 -->   <property name="LOG_HOME" value="${catalina.base:-.}/logs" />         <!-- 日志文件大小,超过这个大小将被压缩 -->   <property name="LOG_MAX_SIZE" value="100MB" />   <!-- 日志输出格式 -->   <property name="LOG_COMMON_PATTERN" value="%d{HH:mm:ss.SSS} [%thread] [%level] %logger - %msg%n" />   <property name="LOG_DEV_PATTERN" value="%d{HH:mm:ss.SSS} [%thread] %-5level %logger{48}:%line - %msg%n" />       <!-- 主日志级别 -->   <property name="ROOT_LEVEL" value="${log.root.level:-DEBUG}" />       <!-- APP 日志级别 -->   <property name="APP_LEVEL" value="${log.app.level:-TRACE}" />   <!-- APP Package 前缀： cn.cstonline.zollty -->   <property name="APP_PACKAGE" value="cn.zollty.lightning" />         <include resource="includedConfig.xml"/>         <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">     <encoder>       <pattern>${LOG_DEV_PATTERN}</pattern>     </encoder>   </appender>         <appender name="FILTER-DATA" class="ch.qos.logback.core.rolling.RollingFileAppender">     <file>${LOG_HOME}/filter.log</file>     <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">       <fileNamePattern>${LOG_HOME}/filter/filter-%d{yyyy-MM-dd}-%i.log.zip</fileNamePattern>       <maxHistory>90</maxHistory>       <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">         <MaxFileSize>100MB</MaxFileSize>       </TimeBasedFileNamingAndTriggeringPolicy>     </rollingPolicy>     <encoder>       <pattern>${LOG_COMMON_PATTERN}</pattern>     </encoder>   </appender>         <appender name="ASYNC1" class="ch.qos.logback.classic.AsyncAppender">     <appender-ref ref="FILTER-DATA" />   </appender>         <include resource="special_log_level.xml"/>       <logger name="${APP_PACKAGE}" level="${APP_LEVEL}" />         <logger name="FILTER-LOGGER" level="${APP_LEVEL}" additivity="false">     <appender-ref ref="ASYNC1" />   </logger>       <root level="${ROOT_LEVEL}">     <!-- Required: exception log -->     <appender-ref ref="FILE_EXCEPTION"/>     <!-- Required: app log  -->     <appender-ref ref="FILE_APP"/>             <!-- Optional： show all debug or trace info -->     <!-- <appender-ref ref="FILE_DEBUG"/> -->     <!-- <appender-ref ref="FILE_TRACE"/> -->             <if condition='p("DEPLOY_ENV").contains("dev")'>       <then>         <appender-ref ref="STDOUT" />       </then>     </if>           </root>     </configuration>

 

 

Logback关闭appender方案

官方提供了shutdownHook配置：

<configurationdebug="true">    <!-- in the absence of the class attribute, assume     ch.qos.logback.core.hook.DelayingShutdownHook -->    <shutdownHook/>   ....  </configuration>

也可以自己定义shutdownHook的class，继承ch.qos.logback.core.hook.ShutdownHookBase，实现run方法即可。

比如：

public class MyShutdownHook extends ShutdownHookBase {

    @Override

    public void run() {

        // do something....

        super.stop();

    }

}

这样即可停止自定义的appender。（注意run方法调用super.stop()即可）

如果有多个Appender需要(顺序)关闭，可以参考如下方法：

import ch.qos.logback.core.Appender; import ch.qos.logback.core.Context; import ch.qos.logback.core.hook.ShutdownHookBase;    public final class APPLogbackShutdownHookManager extends ShutdownHookBase {            private List<Class <? extends Appender>> shutableAppenders;            public APPLogbackShutdownHookManager() {         shutableAppenders = new ArrayList<Class <? extends Appender>>();                // 在此处添加需要shutdown的appender         shutableAppenders.add(MyXXXAppender.class);     }        @Override     public void run() {         this.stop(context);            super.stop();                    // 手动强行停止Logback（最好等应用完全停止后再调用，比如当spring容器销毁后再执行）         //LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory();         //loggerContext.stop();     }        public void stop(Context context) {         for(Class <? extends Appender> cls: shutableAppenders) {             Appender ka = (Appender) context.getObject(cls.getName());             if (ka != null)                 ka.stop();         }     }    }

然后配置：<shutdownHook class="com.zollty.common.APPLogbackShutdownHookManager"/> 即可。

 

Appender关闭不了的问题 解决方法

 

在Appender中的stop方法，无法被调用，

查看Logback源码，可知原因是Appender没有被注册到Context中，解决方法如下：

在自定义的Appender的start()方法末尾增加注册该appender的逻辑：

@Override public void start() {         super.start();                   …………                   // 在末尾加上则两行，将appender注册到Context里面         getContext().register(this);         getContext().putObject(this.getClass().getName(), this); }

 

下面给出一个自定义Appender的完整实现：

功能：将log的数据放在appender里面缓存，定时处理日志数据（比如保存到数据库或者发送给日志收集服务器）

代码如下：

import java.util.Calendar; import java.util.Date; import java.util.concurrent.Executors; import java.util.concurrent.ScheduledExecutorService; import java.util.concurrent.ThreadFactory; import java.util.concurrent.TimeUnit;    import ch.qos.logback.classic.spi.ILoggingEvent; import ch.qos.logback.core.UnsynchronizedAppenderBase;    /**  * 定时推送数据<br>  *   * 可以实现 {@link #handleLog(String)} 方法处理简单日志内容。 <br>  * 也可以重载 {@link #append(ILoggingEvent)} 方法处理复杂日志内容。  *   * @author zollty  * @since 2016-9-3  */ public abstract class TimingAppender extends UnsynchronizedAppenderBase<ILoggingEvent> {            private ScheduledExecutorService scheduledExecutorService;        private long delay;        /**      * 处理日志内容      * @param log 日志内容      */     protected abstract void handleLog(String log);        protected abstract Runnable getRunnable();        @Override     protected void append(ILoggingEvent event) {         handleLog(event.getFormattedMessage());     }        @Override     public void start() {         super.start();         scheduledExecutorService = Executors.newSingleThreadScheduledExecutor(new ThreadFactory() {             @Override             public Thread newThread(Runnable r) {                 Thread t = new Thread(r);                 t.setName("TimingAppenderScheduledThread");                 return t;             }         });         long initialDelay = delay == 60000 ? calcDelayTime() : 1000;         System.out.println(String.format("ScheduledExecutorService start to run. initialDelay=%dms, delay=%dms", initialDelay, delay));         scheduledExecutorService.scheduleWithFixedDelay(getRunnable(), initialDelay, delay, TimeUnit.MILLISECONDS);                    getContext().register(this);         getContext().putObject(this.getClass().getName(), this);     }        public void setDelay(String delay) {         this.delay = Long.valueOf(delay);     }        /**      * 获取距当前时间的下一分钟的毫秒数，例如 当前时间（15:21 32S），那么return （15:22 00S） - （15:21 32S） = 28000MS      */     private static long calcDelayTime() {         Date d1 = new Date();         Calendar calendar = Calendar.getInstance();         calendar.setTime(d1);         calendar.set(calendar.get(1), calendar.get(2), calendar.get(5), calendar.get(11), calendar.get(12), 60);         return calendar.getTime().getTime() - d1.getTime();     }            @Override     public void stop() {       if (!isStarted())         return;          // mark this appender as stopped so that Worker can also processPriorToRemoval if it is invoking aii.appendLoopOnAppenders       // and sub-appenders consume the interruption       super.stop();          scheduledExecutorService.shutdown();       System.out.println("ScheduledExecutorService is stopped.");     } }