最佳实践

最佳实践经验（6条）：

1、根据开发环境、测试环境、生产环境等环境的不同，来配置不同的日志策略。

2、做到在自己的代码中，合理选择日志输出的级别，不要输出大量无意义的调试日志

3、将第三方代码中的不必要的日志过滤掉

4、将日志分类输出，分类的原则是便于查看，或便于自动化分析、入库

5、控制日志文件的保存时间和文件大小

6、最好是能热加载配置，让日志配置的更改能及时生效，便于问题排查

使用指导

一、概述

1、采用dev（开发环境）、test（测试环境）、pre release（预发布、准生产环境）、production（生产环境）等不同的日志配置，根据系统变量、环境变量等自动识别。

2、特殊的记录，需要大批量写入日志文件，应该采用异步线程写文件。

二、日志输出（Appender）分类

分为5个基础类： 

    FILE_EXCEPTION （异常日志，包括ERROR和WARN）

    FILE_APP （应用日志，包括当前应用package下面的日志和 大于等于INFO级别的其他日志）

    FILE_INFO （普通信息日志）

    FILE_DEBUG （调试日志）

    FILE_TRACE（追踪日志）

    SYSOUT（控制台输出，可以包括以上所有日志）

和其他扩展类： 包括异步输出的日志，或者特殊业务日志。

相关补充说明：

1、FILE_APP（应用日志输出，默认为app.log）

    设计它的目的在于，根据作者多年的日志排查经验，希望能在一个日志文件中，集中所有的关键日志信息，而不是把各种关键信息分散在不同的日志中（注意，不同于catalina.out，因为它太杂，而我们想要的是精华部分）。所以，在传统 按error.log、info.log、debug.log分类的基础上，增加一个 “应用日志”分类——即app.log，用来来存放所有的关键日志。什么是关键日志呢，根据经验，我们发现 应用代码自身打印的日志，以及第三方框架和库打印的info级别(含)以上日志，都是关键日志，而其他“非当前应用代码”打印出来的info级别以下的日志，则是非关键日志。

    故，设计了该appender，只输出 “当前应用代码打印的日志，以及其他info级别(含)以上的日志”。

2、FILE_EXCEPTION（异常日志）

    这是在error.log基础上的改进，包含了error和warn信息。因为根据实际经验，warn（警告）也是需要特别关心的。

3、其他日志（INFO、DEBUG、TRACE、SYSOUT）

    有了上面的“应用日志”和“异常日志”，其他日志都显得多余，因为一般都用不上，所以它们通常都不是标配，需要的话自己去配置。

4、自定义的日志输出（不建议）

    保存特殊的记录。我们不建议用“日志文件”来保存特殊的业务相关的数据记录，建议使用异步线程输出到MQ或者MongoDB中。

5、举例说明 （FILE_EXCEPTION、FILE_APP、FILE_INFO 等的区别）：

    假如 当前应用的 Main Package 为 cn.zollty.demo

    ROOT_LEVEL为 trace，应用日志 LEVEL 为 debug

    有以下日志打印：

Logger loggerA = LoggerFactory.getLogger(cn.zollty.demo.Tests.class);
loggerA.trace("--------");
loggerA.debug("--------");
loggerA.info("--------");
loggerA.warn("--------");
loggerA.error("--------");

Logger loggerB = LoggerFactory.getLogger(org.apache.kafka.Consumer.class);
loggerB.trace("--------");
loggerB.debug("--------");
loggerB.info("--------");
loggerB.warn("--------");
loggerB.error("--------");

那么，异常日志（FILE_EXCEPTION）输出的为：

loggerA.warn("--------");

loggerA.error("--------");

loggerB.warn("--------");

loggerB.error("--------");

控制台（SYSOUT）输出的为;

loggerA.debug("--------");

loggerA.info("--------");

loggerA.warn("--------");

loggerA.error("--------");

loggerB.trace("--------");

loggerB.debug("--------");

loggerB.info("--------");

loggerB.warn("--------");

loggerB.error("--------");

应用日志（FILE_APP）输出的为：

loggerA.debug("--------");

loggerA.info("--------");

loggerA.warn("--------");

loggerA.error("--------");

loggerB.info("--------");

loggerB.warn("--------");

loggerB.error("--------");

三、日志归档和保存期限

1、定期对日志文件进行归档、压缩 。

2、保存期限越久越好，但是本机保存的日志最大总容量（当前日志文件+归档压缩后的日志文件 size总和）规定如下：

• 异常日志（error和warn）最多保存 10G（生产、准生产环境至少要保存30天）

• app日志最多保存 10G（生产、准生产环境至少要保存7天）

• trace日志最多保存 1G（仅供开发、测试用，生产环境一般不用）

• debug、info日志最多保存 5G（一般不用，用app日志就够了）

• 其他独立的输出日志视具体需求而定，但原则上最多保存 10G
  

对于超过本地保存容量的日志，根据业务需求决定是否删除或者迁移到其他地方保存。

四、各环境默认日志定义

开发环境

1）默认日志级别定义为：

    app包为TRACE级别。日志的ROOT Level为DEBUG级别。

2）启用 System.out 控制台输出日志；

3）启用error.log为错误和警告日志、app.log为应用日志（包括app包下的日志和其他INFO级别以上的日志）。

测试环境

1）默认日志级别定义为：

    app包为DEBUG级别。日志的ROOT Level为DEBUG级别。

2）禁用 System.out 控制台输出日志；

3）启用error.log为错误和警告日志、app.log为应用日志（包括app包下的日志和其他INFO级别以上的日志）。

生产环境

1）默认日志级别定义为：

    app包为DEBUG级别。日志的ROOT Level为INFO级别。

2）禁用 System.out 控制台输出日志；

3）启用error.log为错误和警告日志、app.log为应用日志（包括app包下的日志和其他INFO级别以上的日志）。

四、根据环境自动选择日志配置

关键点1：使用logback的环境变量定义和读取功能

例如下面的各种环境变量定义：

<!-- 部署的环境类型：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.zollty.demo -->
<property name="APP_PACKAGE" value="cn.zollty.demo" />

其中 ${deploy.env:-dev} 代表的意思是，如果环境变量中没有 deploy.env，则使用默认值dev。

一个小技巧：可以自定义类似下面这个类，在logback初始化之前，先设置变量的值：

<statusListener class="cn.zollty.commons.logbackext.InitConfigOnConsoleStatusListener" />

这个类继承自ch.qos.logback.core.status.OnConsoleStatusListener。

关键点2：使用logback的 if-then 条件语法

<root level="${ROOT_LEVEL}">
  <!-- Required: exception log -->
  <appender-ref ref="FILE_EXCEPTION"/>
  <!-- Required: app log  -->
  <appender-ref ref="FILE_APP"/>

  <if condition='p("DEPLOY_ENV").contains("dev")'>
    <then>
	<appender-ref ref="STDOUT" />
    </then>
  </if>
</root>

参考配置：

logback.xml：

<?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.zollty.demo -->
  <property name="APP_PACKAGE" value="cn.zollty.demo" />
  
  <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>

includedConfig.xml

<?xml version="1.0" encoding="UTF-8" ?>

<included>

  <!-- WARN and ERROR -->
  <appender name="FILE_EXCEPTION" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
      <level>WARN</level>
    </filter>
    <file>${LOG_HOME}/error.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <!-- rollover daily -->
      <fileNamePattern>${LOG_HOME}/error/error-%d{yyyy-MM-dd}-%i.log.zip</fileNamePattern>
      <maxHistory>600</maxHistory>
      <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
        <!-- or whenever the file size reaches 100MB -->
        <MaxFileSize>${LOG_MAX_SIZE}</MaxFileSize>
      </TimeBasedFileNamingAndTriggeringPolicy>
    </rollingPolicy>
    <encoder>
      <pattern>${LOG_COMMON_PATTERN}</pattern>
    </encoder>
  </appender>

  <!-- INFO or Greater -->
  <appender name="FILE_INFO" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
      <level>INFO</level>
    </filter>
    <file>${LOG_HOME}/info.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <fileNamePattern>${LOG_HOME}/info/info-%d{yyyy-MM-dd}-%i.log.zip</fileNamePattern>
      <maxHistory>50</maxHistory>
      <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
        <MaxFileSize>${LOG_MAX_SIZE}</MaxFileSize>
      </TimeBasedFileNamingAndTriggeringPolicy>
    </rollingPolicy>
    <encoder>
      <pattern>${LOG_COMMON_PATTERN}</pattern>
    </encoder>
  </appender>

  <!-- DEBUG or Greater-->
  <appender name="FILE_DEBUG" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
      <level>DEBUG</level>
    </filter>
    <file>${LOG_HOME}/debug.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <fileNamePattern>${LOG_HOME}/debug/debug-%d{yyyy-MM-dd}-%i.log.zip</fileNamePattern>
      <maxHistory>50</maxHistory>
      <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
        <MaxFileSize>${LOG_MAX_SIZE}</MaxFileSize>
      </TimeBasedFileNamingAndTriggeringPolicy>
    </rollingPolicy>
    <encoder>
      <pattern>${LOG_COMMON_PATTERN}</pattern>
    </encoder>
  </appender>

  <!-- TRACE and ALL -->
  <appender name="FILE_TRACE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${LOG_HOME}/trace.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <fileNamePattern>${LOG_HOME}/trace/trace-%d{yyyy-MM-dd}-%i.log.zip</fileNamePattern>
      <maxHistory>10</maxHistory>
      <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
        <MaxFileSize>${LOG_MAX_SIZE}</MaxFileSize>
      </TimeBasedFileNamingAndTriggeringPolicy>
    </rollingPolicy>
    <encoder>
      <pattern>${LOG_COMMON_PATTERN}</pattern>
    </encoder>
  </appender>
  
  <!-- (INFO or Greater) or logname prefix = ${APP_PACKAGE} -->
  <appender name="FILE_APP" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <filter class="cn.zollty.demo.common.PackageOrThresholdFilter">
      <level>INFO</level>
      <prefix>${APP_PACKAGE}</prefix>
    </filter>
    <file>${LOG_HOME}/app.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <fileNamePattern>${LOG_HOME}/app/app-%d{yyyy-MM-dd}-%i.log.zip</fileNamePattern>
      <maxHistory>600</maxHistory>
      <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
        <MaxFileSize>${LOG_MAX_SIZE}</MaxFileSize>
      </TimeBasedFileNamingAndTriggeringPolicy>
    </rollingPolicy>
    <encoder>
      <pattern>${LOG_COMMON_PATTERN}</pattern>
    </encoder>
  </appender>

</included>

special_log_level.xml

<?xml version="1.0" encoding="UTF-8" ?>
<included>

  <logger name="org.apache.zookeeper.ClientCnxn" level="ERROR" />
  <logger name="org.apache.kafka.clients.consumer.internals.ConsumerCoordinator" level="INFO" />
  <logger name="kafka.producer.BrokerPartitionInfo" level="INFO" />
  <logger name="kafka.producer.async.ProducerSendThread" level="INFO" />
  <logger name="kafka.producer.async.DefaultEventHandler" level="INFO" />
  <logger name="org.apache.kafka.common.metrics.Metrics" level="INFO" />
  <logger name="org.apache.kafka.clients.Metadata" level="INFO" />
  
  <logger name="org.apache.kafka.clients.consumer.internals.AbstractCoordinator" level="INFO" />
  <logger name="org.apache.kafka.clients.consumer.internals.Fetcher" level="INFO" />
  <logger name="org.apache.kafka.clients.NetworkClient" level="INFO" />
  
</included>

也可以把变量定义到properties文件中，本地就放在 

src/resources/conf/logback_val.properties

服务器上放在

${catalina.base}/conf/logback_val.properties

配置如下：

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="60 seconds" debug="false">

  <if condition='isDefined("catalina.base")'>
    <then>
      <property file="${catalina.base}/conf/logback_val.properties" />
    </then>
    <else>
      <property resource="./conf/logback_val.properties" />
    </else>
  </if>
  
  ...

logback_val.properties:

# deploy environment : dev, test, pre, prod
deploy.env=dev
# the root log level
log.root.level=DEBUG
# the app log level
log.app.level=TRACE
# to use Kafka LogStash value= "yes" or "no"
log.use.logstash=yes
# LogStash Kafka URL
log.logstash.kafka=172.16.1.164:9092,172.16.1.165:9092,172.16.1.166:9092

同理，可以根据  dev开发环境、test测试环境、prod生产环境来读取不同的配置。

<?xml version="1.0" encoding="UTF-8"?>

<configuration scan="true" scanPeriod="60 seconds" debug="false">

  <property resource="./conf/logback-${deploy.env}.properties" />

  ...

参考资料：

http://logback.qos.ch/manual/configuration.html#conditional