web项目日志记录方案

一、概述

1、采用slf4j作为日志API，采用logback作为日志输出工具，用slf4j桥接方式替换掉log4j和commons-logging。

2、采用trace（追踪）、debug（调试）、info（信息）、warn（警告）、error（错误）、fatal（致命）共6种日志级别。

3、采用dev（开发环境）、test（测试环境）、production（生产环境）等不同的日志配置，根据环境变量自动识别。

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

二、日志级别定义

采用trace（追踪）、debug（调试）、info（信息）、warn（警告）、error（错误）、fatal（致命）共6种日志级别。

log4j建议使用4种级别：优先级从高到低分别是 ERROR、WARN、INFO、DEBUG;如果添加了日志开关，那么会优先展示优先级别高的；

如：在这里定义了INFO级别，则应用程序中所有DEBUG级别的日志信息将不被打印出来。

日志级别使用原则：

1、fatal（致命错误）使用原则

fatal为系统级别的异常，发生fatal错误，代表服务器整个或者核心功能已经无法工作了！！

1）在服务器启动时就应该检查，如果存在致命错误，直接抛异常，让服务器不要启动起来（启动了也无法正常工作，不如不启动）。

2）如果在服务器启动之后，发生了致命的错误，则记录fatal级别的错误日志，最好是同时触发相关的修复和告警工作（比如，给开发和维护人员发送告警邮件）。

2、error（错误）使用原则

error为功能或者逻辑级别的严重异常，发生error级别的异常，代表功能或者重要逻辑遇到问题、无法正常工作。

3、warn（警告）使用原则

warn用在某些逻辑非常规，发生了一些小故障但是没有大的影响，或者重要数据被修改，或者某些操作需要引起重视。

4、info（信息）使用原则

info用于记录一些有用的、关键的信息，一般这些信息出现得不频繁，只是在初始化的地方或者重要操作的地方才记录。

5、debug（调试）使用原则

debug用于记录一些调试信息，为了方便查看程序的执行过程和相关数据、了解程序的动态。

6、trace（跟踪）使用原则

trace用于记录一些更详细的调试信息，这些信息无需每次调试时都打印出来，只在需要更详细的调试信息时才开启。

7、项目稳定运行时的日志量

1）正常情况下，trace日志至少是debug日志的100倍，

trace级别的日志量： debug级别的日志量 > 100 ： 1，

也就是说trace日志非常多，debug日志相对较少。

2）debug级别的日志量： info级别的日志量 > 1000 ： 1，

也就是说正常情况下，info日志很少，只在部分重要位置会输出 info日志。

3）error日志和warn日志，正常情况下，几乎为0，当出现异常时，error日志和warn日志量也在可控范围，不会超过debug级别的最大日志量。

三、日志输出（Appender）分类

分为5个一般类：

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

FILE_APP （应用日志，包括当前应用package下面的日志和DEBUG级别以上的其他日志）

FILE_INFO （普通信息日志）

FILE_DEBUG （调试日志）

FILE_TRACE（追踪日志）

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

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

举例说明：

假如

当前应用的 Main Package 为 cn.zollty.lightning

ROOT_LEVEL为 trace，应用日志 LEVEL 为 debug

有以下日志打印：

Logger loggerA = LoggerFactory.getLogger(cn.zollty.lightning.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("--------");

2、历史日志文件

异常日志（error和warn）最多保存 9000 M（生产，测试）

app日志最多保存 9000 M （生产，测试）

trace日志最多保存 1000 M （仅供测试用，一般不用）

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

四、各环境默认日志定义

开发环境

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

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

2）

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

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

测试环境

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

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

2）

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

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

生产环境

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

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

2）

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

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

五、根据环境自动选择日志配置（借助Logback）

关键点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.lightning -->
<property name="APP_PACKAGE" value="cn.zollty.lightning" />

其中 ${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.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>

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>90</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.lightning.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>90</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:

# \u90E8\u7F72\u7684\u73AF\u5883\u7C7B\u578B\uFF1Adev\u3001test\u3001product
deploy.env=dev
# \u4E3B\u65E5\u5FD7\u7EA7\u522B
log.root.level=DEBUG
# APP \u65E5\u5FD7\u7EA7\u522B
log.app.level=TRACE
# Kafka LogStash \u9009\u62E9\u4F7F\u7528 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

log4j中进行过滤的方法：

log4j中log.isDebugEnabled(), log.isInfoEnabled()和log.isTraceEnabled()作用 :
  1、项目在应用log4j打印Debug,Info和Trace级别的log时需要加上对应的三个方法进行过滤，代码如下：
		if (log.isDebugEnabled()) {
		    log.debug(" From: " + req.getFrom().toString() + 
		                  " To: " + req.getTo().toString() + 
		                  " CallId: " + req.getCallId() + 
		                  " msg:" + msg);
		}
	其作用是因为Debug,Info和Trace一般会打印比较详细的信息，而且打印的次数较多，如果我们不加log.isDebugEnabled()等
	进行预先判断，当系统loglevel设置高于Debug或Info或Trace时，虽然系统不会答应出这些级别的日志，但是每次还是会拼接
	参数字符串，影响系统的性能。
  2、错误的优化方法
	部分编码人员因为不了解机制，从代码复用性和简洁性而言定义如下函数来封装
	    private void debug(String msg) {
	        if (log.isDebugEnabled()) {
	            log.debug(msg);
	        }
	    }
	其实这种封装方式是错误的，因为当系统中调用debug(msg)函数还是出现字符串的拼接。
 
结论：这3个方法是对项目的优化方法，加这个方法目的在于如果代码中存在连接字符串的情况，打印信息时会出现太多的拼接字符串影响
       系统性能。如果系统中是固定字符串加不加都可以。

log4j的使用:

##define an appender named console
log4j.appender.console=org.apache.log4j.ConsoleAppender
#The Target value is System.out or System.err（out kong zhi tai xian shi wei hei se;err kong zhi tai xian shi hong se）
log4j.appender.console.Target=System.out
#set the layout type of the apperder
log4j.appender.console.layout=org.apache.log4j.PatternLayout
#set the layout format pattern(ri zhi ge shi)
log4j.appender.console.layout.ConversionPattern=[%-5p][%d{yyyy-MM-dd HH:mm:ss}] %c %L %m%n


##define an appender named file(shu chu dao wen jian)
log4j.appender.file=org.apache.log4j.FileAppender
#define the file path and name
log4j.appender.file.File=d:/logfile.txt
#set the layout type of the apperder
log4j.appender.file.layout=org.apache.log4j.PatternLayout
#set the layout format pattern
log4j.appender.file.layout.ConversionPattern=[%-5p][%d{yyyy-MM-dd HH:mm:ss}] %c %L %m%n


##define an appender named rollfile(shu chu dao wen jian,dan da dao zhi ding nei cun,hui chong xin cheng cheng yi ge wen jian)
log4j.appender.rollfile=org.apache.log4j.RollingFileAppender
#define the file path and name
log4j.appender.rollfile.File=d:/logrollfile.txt
#set the log's size(zhi ding ri zhi wen jian da xiao)
log4j.appender.rollfile.MaxFileSize=10KB
#set the layout type of the apperder
log4j.appender.rollfile.layout=org.apache.log4j.PatternLayout
#set the layout format pattern
log4j.appender.rollfile.layout.ConversionPattern=[%-5p][%d{yyyy-MM-dd HH:mm:ss}] %c %L %m%n


##define a logger(zhi ding ri zhi ji bie he shi yong na xie zui jia qi)
#log4j.logger.全限定性类名或接口名=INFO,console,file,rollfile
log4j.rootLogger=INFO,console,file,rollfile

log4j2的使用：

<?xml version="1.0" encoding="UTF-8"?>
<-- status 是否输出日志中的日志（引入了日志的jar包） -->
<configuration status="OFF">
	<appenders>
	    <-- SYSTEM_OUT/SYSTEM_ERR -->
		<Console name="myConsole" target="SYSTEM_OUT">
			<PatternLayout pattern="[%-5p][%d{yyyy-MM-dd HH:mm:ss}] [%c %L] %m%n" />
		</Console>
		<-- append="true" 表示追加，不删除之前的日志；false是会删除之前的日志	 -->
		<File name="myLogFile" fileName="log/test.log" append="true">
            <PatternLayout pattern="[%-5p][%d{yyyy-MM-dd HH:mm:ss}] [%c %L] %m%n"/>
        </File>
		<-- logs/app.log 项目根目录log -->
        <RollingFile name="myRollingFile" fileName="logs/app.log"
					 <-- 按月来管理日志 log.gz 的.gz为压缩格式 -->
                     filePattern="logs/$${date:yyyy-MM}/app-%d{MM-dd-yyyy}-%i.log.gz">
					 
					 <--
					 按日来管理日志  filePattern="logs/$${date:yyyy-MM-dd}/app-%d{MM-dd-yyyy}-%i.log.gz"
					 -->
					
					 
            <PatternLayout pattern="[%-5p][%d{yyyy-MM-dd HH:mm:ss}] [%c %L] %m%n"/>
			<-- 日志文件大小，超出这个空间，会重新生成一个文件 -->
            <SizeBasedTriggeringPolicy size="1KB"/>
        </RollingFile>
	</appenders>
	
	<loggers>
		<!-- 
		<logger name="全限定类名或接口名" level="info">
			<appender-ref ref="myConsole" />
		</logger>
		 -->
		<-- 日志输出级别 -->
		<root level="info">
			<-- 使用那些追加器 -->
			<appender-ref ref="myConsole" />
			<!-- <appender-ref ref="myLogFile" /> -->
			<!-- <appender-ref ref="myRollingFile" /> -->
		</root>
	</loggers>
	
</configuration>

参考资料：

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

posted @ 2018-03-16 10:14 qqyong 阅读(1031) 评论(0) 编辑收藏举报

会员力量，点亮园子希望

刷新页面返回顶部

web项目日志记录方案

公告