日志
对于一个大型网站系统而言，日志是后端应用程序必须要引入的模块，日志有利于追查Bug和记录用户操作。每个编程语言都有很多现成的日志框架，而Java的日志框架也有很多，如log4j2、Logback、SLF4J等，这些日志框架都可以让后端应用程序按照一定的规则输出日志文件。
在大型网站系统当中，仅仅把日志记录下来是远远不够的。大型网站系统需要一个完整的日志系统，日志系统除了需要收集日志并将其记录下来以外，还需要做日志筛选、用户行为记录追溯及风险预警等工作。
不过，在项目中前期，或者单独调试某个后端应用程序时，仍然需要使用日志模块。这里以log4j2为例，通过日志模块引入和规范化日志记录两个方面对日志模块的使用进行介绍。
1.日志模块引入
引入日志模块的具体操作步骤如下：
（1）引入log4j2依赖包。需要在工程配置文件（build.gradle）中添加log4j2依赖包，如代码4.32所示。需要注意的是，如果不去除Spring Boot中原有日志模块的话，那么新引入的日志模块与原有日志模块会产生冲突。
代码4.32 build.gradle中添加log4j2依赖包
…
configurations {
//去除Spring Boot中原有的日志模块
all*.exclude group: 'org.springframework.boot', module: 'spring-boot
starter-logging'
}
…
dependencies {
…
//dependencies中添加log4j2的依赖包
implementation 'org.springframework.boot:spring-boot-starter-log4j2'
…}
…
（2）同步工程配置。修改完build.gradle文件后，log4j2的依赖包在同步工程配置后才会被下载和引入。在IntelliJ IDEA中单击“同步”按钮即可同步工程配置，如图4.59所示。
图4.59 在IntelliJ IDEA中同步build.gradle配置
（3）创建log4j2的配置文件log4j2.xml，其内容及设置说明如代码4.33所示，更详细的说明请参考官方说明（https://logging.apache.org/log4j/2.x/manual/index.html）。另外，日志配置文件一般与后端应用程序的配置文件放在一起，如图4.60所示。
图4.60 日志配置文件存放位置
说明：图4.60中的“配置文件目录位置”和“后端应用程序配置文件名”都不是默认设置。关于“配置文件目录位置”和“后端应用程序配置文件名”的设置可参考前面小节中的讲解。
代码4.33 log4j2.xml文件的内容及其配置
<?xml version="1.0" encoding="UTF-8"?>
<!-- monitorInterval：检查更新的时间间隔，单位为s。
在程序运行期间，log4j2能够自动检测日志配置文件是否有更新，如果有更新则自动加载新设
置-->
<configuration monitorInterval="1800">
<!--配置变量，变量会被后续设置使用-->
<properties>
<!-- 设置日志格式的变量：%d：获取日期时间；
%level：日志等级；
%msg：日志消息，如ERROR、INFO、DEBUG等
%n：换行符-->
<property name="LOG_PATTERN"
value="[%d{yyyy-MM-dd}][%d{HH:mm:ss}][%level]%msg%n" />
<!-- 设置日志存储路径的变量 -->
<property name="FILE_PATH" value="D:/logs/backend/demo" />
</properties>
<!-- 设置日志输出源，如设置日志输出格式、设置日志文件名等 -->
<appenders>
<!-- 设置Console（控制台）输出日志格式，一般在开发工具调试时使用 -->
<console name="Console" target="SYSTEM_OUT">
<!--输出日志的格式，采用properties中设置的LOG_PATTERN变量-->
<patternLayout pattern="${LOG_PATTERN}"/>
</console>
<!-- 设置记录INFO和DEBUG日志等级的日志文件，当符合存档策略时在（<policies></policies>中设置），则会自动压缩并另存为存档文件。
fileName：日志文件名，使用properties中设置的FILE_PATH变量。在此例中，输出文件名为D:/logs/backend/demo/web-info.log。
immediateFlush：接收到日志后，是否立即输出到文件中。这个一般设置为false，设置为true会严重影响接口的并发能力。
filePattern：存档文件名，在此例中，归档文件名为（以2020-2-23为例）D:/logs/backend/demo/web-info/web-info-2020-2-23_1.log.gz-->
<rollingFile name="RollingFileInfo" fileName="${FILE_PATH}/web
info.log"
immediateFlush="false"
filePattern="${FILE_PATH}/web-info/web-info-%d{yyyy-MM
dd}_%i.log.gz">
<!-- 输出日志的格式，采用properties中设置的LOG_PATTERN变量 -->
<patternLayout pattern="${LOG_PATTERN}"/>
<!-- 筛选接收的日志等级，接收INFO和DEBUG等级的日志 -->
<filters>
<thresholdFilter level="error" onMatch="DENY" onMismatch=
"NEUTRAL"/>
<thresholdFilter level="info" onMatch="ACCEPT" onMismatch=
"DENY"/>
<thresholdFilter level="debug" onMatch="ACCEPT" onMismatch=
"DENY"/>
</filters>
<!-- 设置存档策略，此例为：每天自动存档，日志文件超过20MB也会存档 -->
<policies>
<!-- 设置时间的存档策略，interval的时间精度与filePattern的时间精
度一致，因为filePattern只设置到日期，所以这里的interval="1"指的是1天-->
<timeBasedTriggeringPolicy interval="1"/><!-- 设置文件大小的存档策略-->
<sizeBasedTriggeringPolicy size="20MB"/>
</policies>
<!-- 设置保留多少个日志文件，日志文件个数超过max的值会自动覆盖 -->
<defaultRolloverStrategy max="15"/>
</rollingFile>
<!-- 设置记录error日志等级的日志文件，配置格式与上面“设置记录INFO和DEBUG
日志等级的日志文件”相同，这里不展开介绍。
在此例子中，ERROR日志的日志文件名为D:/logs/backend/demo/web-error.log，归档文件名为（以2020-2-23为例）
D:/logs/backend/demo/web-error/web-error-2020-2-23_1.log.gz-->
<rollingFile name="RollingFileError" fileName="${FILE_PATH}/web
error.log"
immediateFlush="false"
filePattern="${FILE_PATH}/web-error/web-error-%d{yyyy-MM
dd}_%i.log.gz">
<patternLayout pattern="${LOG_PATTERN}"/>
<filters>
<thresholdFilter level="error" onMatch="ACCEPT" onMismatch=
"DENY"/>
</filters>
<policies>
<timeBasedTriggeringPolicy interval="1"/>
<sizeBasedTriggeringPolicy size="20MB"/>
</policies>
<defaultRolloverStrategy max="15"/>
</rollingFile>
</appenders>
<!-- 设置日志源，需要在这里关联日志输出源（<appenders></appenders>）才能输出到对
应文件当中 -->
<loggers>
<!-- 设置输出日志等级，默认情况下，不会输出比该日志等级低的日志。
在此例中，只输出FATAL、ERROR、WARN、INFO的日志。
日志级别以及优先级排序为OFF > FATAL > ERROR > WARN > INFO > DEBUG >
TRACE > ALL，其中OFF是不输出所有日志-->
<root level="info">
<!-- 关联输出源，其中ref中的值需要与<rollingFile></rollingFile>中
的name对应 -->
<!-- 在非调试环境下，需要关闭控制台的日志输出（去掉下面第一行就可以了） -->
<AppenderRef ref="Console" />
<AppenderRef ref="RollingFileInfo" />
<AppenderRef ref="RollingFileError" />
</root>
</loggers>
</configuration>
（4）引入日志配置文件。在后端应用程序配置文件中指定日志配置文件路径后，才能生效。在如图4.60所示的工程目录结构中，需要在demo.properties文件中添加日志配置文件的路径，如代码4.34所示，其中，classpath:log4j2.xml为具体的路径。
代码4.34 在后端应用程序的配置文件中添加日志配置文件的路径
#设置日志配置文件的路径
logging.config=classpath:log4j2.xml
（5）程序中记录日志，如代码4.35所示。对应的日志输出结果如代码4.36所示，其中，由于log4j2.xml（日志配置文件）设置的日志输出等级为INFO，所以DEBUG等级的日志没有被记录下来。
说明：日志配置文件的相关说明请参照代码4.33，其中，设置输出日志等级的位置为<root level="info">…</root>。
代码4.35 代码中记录日志
//需要引入的日志依赖类
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
public class XX{
…
//获取日志对象
private static final Logger LOGGER = LogManager.getLogger();
…
public void Function(){
…
//输出INFO级别的日志
LOGGER.info("info log test.");
//输出ERROR级别的日志
LOGGER.error("error log test.");
//输出DEBUG级别的日志
LOGGER.debug("debug log test.");
…
}
…
}
代码4.36 日志输出结果
[2020-04-20][17:46:17][INFO]info log test.
[2020-04-20][17:46:17][ERROR]error log test.
（6）如果实现了4.3.3小节中的后端应用程序与配置文件分离，那么日志配置文件也应该从后端应用程序中分离出来。按常理来说，只要在配置文件中设置日志配置文件路径就可以了（如logging.config=/home/tomcat/appconfig/log4j2.xml），但是由于某种冲突，这样的配置是不起作用的。
因此，要想实现后端应用程序引用外部的日志配置文件，需要通过“添加启动参数”和“修改代码（ServletInitializer.java）”才能实现。具体做法是，“添加启动参数”需要在Tomcat目录下的/conf/catalina.properties文件中添加如代码4.37所示的设置，修改后的代码如代码4.38所示，其中，xxx_log4j2.xml为日志配置文件名。最终，配置文件和日志配置文件集中管理的效果如图4.61所示。
图4.61 配置文件和日志配置文件集中管理
代码4.37 设置日志配置文件所在目录
…
#后端应用程序的外部配置文件所在目录，详见4.3.3节的介绍
spring.config.location=${catalina.home}/appconfig/
#新增代码，设置日志配置文件所在目录，一般与后端应用程序的外部配置文件目录相同
logging.config=${catalina.home}/appconfig/
…
代码4.38 修改后的ServletInitializer.java文件
…
public class ServletInitializer extends SpringBootServletInitializer {
@Override
protected SpringApplicationBuilder configure(SpringApplicationBuilder
application) {
//新增代码，补全启动参数（logging.config）的文件名
String loggingConfig = System.getProperty("logging.config");
if(!loggingConfig.isEmpty()) {
System.setProperty("logging.config", loggingConfig+"xxx_
log4j2.xml");
}
//设置后端应用程序的外部配置文件名，详见4.3.3小节的介绍
return application
.properties("spring.config.name=xxx")
.sources(xxApplication.class);
//初始工程的代码，需要去除
//return application.sources(xxApplication.class);
}
}
2.规范化日志记录
日志记录是一个十分开放的行为，原则上，只要记录的日志能“定位问题发生的位置”和“记录某些重要的用户操作”就可以了。但是，在实际项目当中，由于日志对功能的实现是不产生影响的，所以日志通常都是通过一次次问题修复而得到补充的。而这种“补丁型”日志，通常是混乱的。混乱的日志对于“定位问题发生的位置”和“追查某些重要的用户操作”都不能起到很好的作用，因此，日志记录需要规范化。
注意：日志记录的规则需要在项目前期定好，在开发过程中吸收规整化日志的工作量。项目后期再整理日志是很不理智的行为，因为后期整理日志需要花费大量的时间去梳理和理解业务代码，而这部分工作量是很难预估且十分枯燥的，最后整理日志的结果往往也是不尽人意的。
规范化日志记录可以从限制日志等级、明确日志记录位置、添加日志跟踪码等方面进行考虑。
（1）限制日志等级。日志模块一般都有等级划分，以log4j2为例，其日志等级有6种，分别为TRACE（追踪调试）、DEBUG（调试）、INFO（信息）、WARNING（警告）、ERROR（错误）和FATAL（致命错误）。每个日志等级看上去都有相对明确的分工和含义，但是在实际应用当中，这些日志等级的具体用途其实相当模糊，很多时候，都很难界定一个日志应该归类为哪一个等级。一旦出现这种模糊规则，就会出现一人一个样的做法，最后导致“五花八门”的日志等级划分原则。
因此，规整化日志需要限制日志等级。一般情况下，后端应用程序使用DEBUG、INFO和ERROR三个日志等级就足够了，这三个日志等级的分工和协助如图4.62所示。
图4.62 DEBUG、INFO和ERROR日志等级的分工和协助
其中，DEBUG日志在运行时不生效，需要打开调试模式（修改日志输出等级）后，才能记录DEBUG日志。
（2）明确日志记录位置。在限制了日志等级后，需要解决“补丁式日志”的问题，避免日志不够全面的情况。而解决“补丁式日志”的关键，是明确日志记录位置。但是，明确日志记录位置是一件很难实现的事情，因为接口程序与接口程序之间很难找到共性。
不过，如果实现了4.3.2小节中介绍的“限制函数调用层级”“公共模块”和“错误机制”，那么接口程序会变成流水线式的处理方式。在流水线式的接口程序中明确日志记录位置是相对容易的，如图4.63所示。
图4.63 明确日志位置
其中，每个接口只需要在“接收请求”“数据库操作”和“返回结果”这三部分添加日志就可以了，其余日志都在公共模块里，而且公共模块里的日志是一次添加全局有效的。
说明：Dao层（数据库操作）其实也可以做成一个公共模块，这样可以省掉一些日志工作量。另外，虽然数据库本身可以自动记录日志，但是数据库自身的日志不能包含用户身份信息，即不能追溯用户操作，所以Dao层（数据库操作）的日志是有必要记录的。
（3）添加日志跟踪码。即使日志被记录得十分详细，分析日志也是一件很麻烦的事情。同一时刻，后端应用程序可能会同时处理多个请求，以至于多个请求的日志是混合在一起的，在不经过特殊处理的情况下，根本没法分辨哪几条日志是属于同一个请求的。像这种无法区分请求的日志，被记录下来也是浪费资源。
因此，需要在每条日志中添加日志跟踪码，标记同一请求的日志。跟踪码的本质，就是同一请求输出日志时，都多加一个相同的字符串。如果使用的是log4j2日志模块，可以在不改变原有日志输出代码的前提下，添加日志跟踪码。
首先，需要修改日志配置文件中的日志输出格式，如代码4.39所示，其中[%X{requestId}]为新增的跟踪码格式。
代码4.39 修改日志输出格式
…
<!-- 此段设置截取自代码4.33的，单独设置是不起作用的 -->
<!-- 设置日志格式的变量：
%d：获取日期时间；
%level：日志等级；
%X{requestId}：跟踪码；
%msg：日志消息，如ERROR、INFO、DEBUG等；
%n：换行符-->
<property name="LOG_PATTERN"
value="[%d{yyyy-MM-dd}][%d{HH:mm:ss}][%level][%X{requestId}]
%msg%n" />
…
修改完日志配置文件之后，需要在每个接口程序中添加“生成跟踪码”的代码，如代码4.40所示，其中，代码中的函数为Controller层中的接口的入口函数，requestId对应代码4.39中的跟踪码标识。
代码4.40 添加“生成跟踪码”的代码
…
@Controller
…
@RequestMapping(value="…",method = RequestMethod.POST)
@ResponseBody
public JSONObject XXX(@RequestBody String requestParam, HttpServlet
Response response) {
//在每个接口的入口函数都需要添加以下“生成跟踪码”代码
ThreadContext.put("requestId", UUID.randomUUID().toString());
…
}
…修改日志跟踪码后，能清晰地识别不同请求的日志，日志输出结果如代码4.41所示，其中，62e3300c-e0a0-40cd-be80-4320d40ddc2c和00000000-0000-0000-0000-000000000000是日志追踪码。
代码4.41 添加“日志跟踪码”后的日志输出结果
[2020-04-20][17:46:17][INFO][62e3300c-e0a0-40cd-be80-4320d40ddc2c]info
log test_1.
[2020-04-20][17:46:17][INFO][00000000-0000-0000-0000-000000000000]info
log test_1.
[2020-04-20][17:46:17][INFO][00000000-0000-0000-0000-000000000000]info
log test_2.
[2020-04-20][17:46:17][INFO][62e3300c-e0a0-40cd-be80-4320d40ddc2c]info
log test_2.
[2020-04-20][17:46:17][INFO][62e3300c-e0a0-40cd-be80-4320d40ddc2c]info
log test_3.
本文给大家讲解的内容是大型网站架构的技术细节：后端架构规整化java日志框架
- 下篇文章给大家讲解的内容是大型网站架构的技术细节：后端架构规整化自研框架Once
- 感谢大家的支持！