从零开始实现放置游戏（五）：管理系统搭建之实现切面日志

小篱

上一章，我们初步实现了后台管理系统的增删查改功能。然而还有很多功能不完善。这一章，我们先把系统日志搭建起来，不管是生产问题排查，还是方便开发调试，日志都是必不可少的核心功能。所谓切面日志，比如说，我们想把每个方法的入参都记录日志，那需要在每个方法里都写一行记录参数的语句，非常繁琐。所以需要提取出切面“方法执行前”，“方法执行后”等等，然后在这个切面里进行编程，记录入参的语句只需要写一次。整体的流程大致如下图：

这里我们以rms模块为例，其他模块需要记录日志的地方参照本模块即可。

一、引入依赖

java里，日志的实现一般是common-logging+log4j2或slf4j+logback，其中common-logging和slf4j是接口定义，log4j2和logback是具体实现。这里我们使用log4j，common-logging在其他包中已经间接引用了，无需重复添加，在pom中添加log4j的依赖即可（这里版本是2.11.2，也称log4j2，和1.x版本的区别较大，配置不通用，在网上学习时需注意）：

1. <!-- 日志相关 -->
   
2. <dependency>
   
3.     <groupId>org.apache.logging.log4j</groupId>
   
4.     <artifactId>log4j-core</artifactId>
   
5.     <version>2.11.2</version>
   
6. </dependency>

复制代码

二、添加配置文件

在"/resources/"资源文件目录下新建"log4j2.xml"，这是log4j的默认配置路径和文件名。

1. <?xml version="1.0" encoding="UTF-8"?>
   
2. <Configuration status="OFF" monitorInterval="1800">
   
3.     <properties>
   
4.         <property name="LOG_HOME">/logs/idlewow-rms/</property>
   
5.     </properties>
   
6.     <Appenders>
   
7.         <Console name="Console" target="SYSTEM_OUT">
   
8.             <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
   
9.         </Console>
   
10.         <RollingFile name="info" fileName="${LOG_HOME}/info.log"
    
11.                      filePattern="${LOG_HOME}/info-%d{yyyyMMdd}-%i.log"
    
12.                      immediateFlush="true">
    
13.             <!-- 只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch） -->
    
14.             <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
    
15.             <PatternLayout pattern="%d{HH:mm:ss.SSS} %level [%thread][%X{sessionId}][%file:%line] - %msg%n"/>
    
16.             <Policies>
    
17.                 <TimeBasedTriggeringPolicy interval="1" modulate="true" />
    
18.                 <SizeBasedTriggeringPolicy size="20 MB"/>
    
19.             </Policies>
    
20.         </RollingFile>
    
21.         <RollingFile name="warn" fileName="${LOG_HOME}/warn.log"
    
22.                      filePattern="${LOG_HOME}/warn-%d{yyyyMMdd}-%i.log"
    
23.                      immediateFlush="true">
    
24.             <ThresholdFilter level="warn" onMatch="ACCEPT" onMismatch="DENY"/>
    
25.             <PatternLayout pattern="%d{HH:mm:ss.SSS} %level [%thread][%X{sessionId}][%file:%line] - %msg%n"/>
    
26.             <Policies>
    
27.                 <TimeBasedTriggeringPolicy interval="1" modulate="true"  />
    
28.                 <SizeBasedTriggeringPolicy size="20 MB"/>
    
29.             </Policies>
    
30.             <!-- 同一文件夹下最多保存20个日志文件，默认为7 -->
    
31.             <DefaultRolloverStrategy max="20"/>
    
32.         </RollingFile>
    
33.         <RollingFile name="error" fileName="${LOG_HOME}/error.log"
    
34.                      filePattern="${LOG_HOME}/error-%d{yyyyMMdd}-%i.log"
    
35.                      immediateFlush="true">
    
36.             <ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/>
    
37.             <PatternLayout pattern="%d{HH:mm:ss.SSS} %level [%thread][%X{sessionId}][%file:%line] - %msg%n"/>
    
38.             <Policies>
    
39.                 <TimeBasedTriggeringPolicy interval="1" modulate="true"  />
    
40.                 <SizeBasedTriggeringPolicy size="20 MB"/>
    
41.             </Policies>
    
42.             <DefaultRolloverStrategy max="20"/>
    
43.         </RollingFile>
    
44.     </Appenders>
    
45.     <Loggers>
    
46.         <!--过滤掉spring和mybatis的一些无用的DEBUG信息-->
    
47.         <logger name="org.springframework" level="INFO"></logger>
    
48.         <logger name="org.mybatis" level="INFO"></logger>
    
49.         <Root level="all">
    
50.             <AppenderRef ref="Console"/>
    
51.             <AppenderRef ref="info"/>
    
52.             <AppenderRef ref="warn"/>
    
53.             <AppenderRef ref="error"/>
    
54.         </Root>
    
55.     </Loggers>
    
56. </Configuration>

复制代码

在这个配置文件中，我们定义了日志存放路径"/logs/idlewow-rms/"，windows下默认D盘。控制台的日志输出格式，以及3个级别INFO,WARN,ERROR的文件输出方式。同时把spring组件的日志级别提高到info，过滤掉debug信息。

以info级别的日志为例，我们定义了日志的输出格式"[时间][日志级别][线程名称][SessionId][文件名称-代码行数]-日志信息。日志的滚动策略，按天滚动，每1天生成1个日志文件，或大于20MB时，生成一个日志文件。

三、日志打印SessionId

上面的配置中，我们定义了日志需要打印Sessionid，主要是方便精准定位问题。但log4j默认不支持此功能，需要我们单独实现一个Filter，在请求进来时，获取sessionId，并存到log4j的上下文中。

1. package com.idlewow.rms.filter;
   
2. 
   
3. import org.apache.logging.log4j.ThreadContext;
   
4. 
   
5. import javax.servlet.Filter;
   
6. import javax.servlet.FilterChain;
   
7. import javax.servlet.FilterConfig;
   
8. import javax.servlet.ServletException;
   
9. import javax.servlet.ServletRequest;
   
10. import javax.servlet.ServletResponse;
    
11. import javax.servlet.http.HttpServletRequest;
    
12. import javax.servlet.http.HttpSession;
    
13. import java.io.IOException;
    
14. 
    
15. public class LogSessionFilter implements Filter {
    
16.     @Override
    
17.     public void init(FilterConfig filterConfig) throws ServletException {
    
18.     }
    
19. 
    
20.     public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
    
21.         try {
    
22.             HttpSession session = ((HttpServletRequest) request).getSession(false);
    
23.             if (session != null) {
    
24.                 ThreadContext.put("sessionId", session.getId());
    
25.             }
    
26. 
    
27.             chain.doFilter(request, response);
    
28.         } finally {
    
29.             ThreadContext.remove("sessionId");
    
30.         }
    
31.     }
    
32. 
    
33.     @Override
    
34.     public void destroy() {
    
35.     }
    
36. }

复制代码

Filter是servlet相关的机制，因此需要在web.xml文件中添加以下配置：

1. <!-- log4j记录session -->
   
2. <filter>
   
3.     <filter-name>logSessionFilter</filter-name>
   
4.     <filter-class>com.idlewow.rms.filter.LogSessionFilter</filter-class>
   
5. </filter>
   
6. <filter-mapping>
   
7.     <filter-name>logSessionFilter</filter-name>
   
8.     <url-pattern>/*</url-pattern>
   
9. </filter-mapping>

复制代码

四、具体使用

配置全部完成，在我们想要使用log4j打印日志时，需要先获取一个logger，一般我们在contoller里声明一个final的成员变量，如下：

1. private final Logger logger = LogManager.getLogger(this.getClass().getName());

复制代码

然后，在各个方法中，想记录日志时，只需像下面这样，即可打印对应级别的日志，

1. logger.info("hello world");
   
2. logger.warn("hello world");
   
3. logger.error("hello world");

复制代码

通常，在打印异常时，还会打印堆栈信息，方便定位问题，如下（在第一个参数传入异常信息，第二个参数传入异常对象）：

1. logger.error(ex.getMessage(), ex);

复制代码

五、切面日志的实现

上面的日志功能，已经能让我们在程序中随时记录日志，下面我们实现切面日志的功能。这里需要依赖的两个包，spring-aop和aspectjweaver，前面我们已经引用过了。

然后，我们需要一个类，定义切点、切面方法。新建一个包com.idlewow.rms.config，在此包下新建类LogAspect，代码如下：

1. package com.idlewow.rms.config;
   
2. 
   
3. import com.alibaba.fastjson.JSON;
   
4. import com.idlewow.admin.model.SysAdmin;
   
5. import com.idlewow.rms.controller.BaseController;
   
6. import com.idlewow.rms.vo.RequestLog;
   
7. import org.apache.logging.log4j.LogManager;
   
8. import org.apache.logging.log4j.Logger;
   
9. import org.aspectj.lang.JoinPoint;
   
10. import org.aspectj.lang.annotation.After;
    
11. import org.aspectj.lang.annotation.AfterReturning;
    
12. import org.aspectj.lang.annotation.AfterThrowing;
    
13. import org.aspectj.lang.annotation.Aspect;
    
14. import org.aspectj.lang.annotation.Before;
    
15. import org.aspectj.lang.annotation.Pointcut;
    
16. import org.springframework.stereotype.Component;
    
17. import org.springframework.web.context.request.RequestContextHolder;
    
18. import org.springframework.web.context.request.ServletRequestAttributes;
    
19. 
    
20. import javax.servlet.http.HttpServletRequest;
    
21. import javax.servlet.http.HttpSession;
    
22. import java.util.Date;
    
23. import java.util.Random;
    
24. 
    
25. @Aspect
    
26. @Component
    
27. public class LogAspect {
    
28. 
    
29.     private final static Logger logger = LogManager.getLogger(LogAspect.class);
    
30. 
    
31.     // ..表示包及子包 该方法代表controller层的所有方法
    
32.     @Pointcut("execution(public * com.idlewow.rms.controller..*.*(..))")
    
33.     public void commonPoint() {
    
34.     }
    
35. 
    
36.     @Pointcut("@annotation(com.idlewow.rms.support.annotation.LogResult)")
    
37.     public void returnPoint() {
    
38.     }
    
39. 
    
40. 
    
41.     @Before("commonPoint()")
    
42.     public void before(JoinPoint joinPoint) throws Exception {
    
43.         HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();
    
44.         HttpSession session = request.getSession(false);
    
45.         String username = "anyone";
    
46.         if (session != null && session.getAttribute(BaseController.LoginUserKey) != null) {
    
47.             username = ((SysAdmin) session.getAttribute(BaseController.LoginUserKey)).getUsername();
    
48.         }
    
49. 
    
50.         String trackId = username + "_" + System.currentTimeMillis() + "_" + new Random().nextInt(100);
    
51.         request.setAttribute("ct_begin", new Date().getTime());
    
52.         request.setAttribute("ct_id", trackId);
    
53.         RequestLog requestLog = new RequestLog();
    
54.         requestLog.setUrl(request.getRequestURI());
    
55.         requestLog.setType(request.getMethod());
    
56.         requestLog.setIp(request.getRemoteAddr());
    
57.         requestLog.setMethod(joinPoint.getSignature().toShortString());
    
58.         requestLog.setArgs(joinPoint.getArgs());
    
59.         logger.info("[" + trackId + "]请求开始：" + requestLog.toString());
    
60.     }
    
61. 
    
62.     @After("commonPoint()")
    
63.     public void after(JoinPoint joinPoint) {
    
64.         HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();
    
65.         String trackId = request.getAttribute("ct_id").toString();
    
66.         long totalTime = new Date().getTime() - (long) request.getAttribute("ct_begin");
    
67.         logger.info("[" + trackId + "]请求耗时：" + totalTime + "ms");
    
68.     }
    
69. 
    
70.     @AfterReturning(returning = "result", pointcut = "commonPoint()")
    
71.     public void afterReturn(JoinPoint joinPoint, Object result) throws Exception {
    
72.         HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();
    
73.         String trackId = request.getAttribute("ct_id").toString();
    
74.         logger.info("[" + trackId + "]请求结果：" + JSON.toJSONString(result));
    
75.     }
    
76. 
    
77.     @AfterThrowing(value = "commonPoint()", throwing = "t")
    
78.     public void afterThrow(JoinPoint joinPoint, Throwable t) {
    
79.         HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();
    
80.         String trackId = request.getAttribute("ct_id").toString();
    
81.         logger.error("[" + trackId + "]系统异常：" + t.getMessage(), t);
    
82.     }
    
83. }

复制代码

这里我们定义了2个切点，commonPoint表示controller包下的所有public方法，returnPoint表示所有打了LogResult注解的方法（这是我们自定义的一个注解）。

然后实现了4个切面方法，目前对应的都是commonPoint切点。

其中，before在每次方法执行前都会执行，我们在这个方法里打印info级别的日志，记录请求URL、IP、入参等信息，同时记录请求起始时间，并分配一个trackId用来定位问题（假如同一个用户瞬间执行某个请求N次，SessionId都是相同的，我们就无法确定这N次中，每个返回数据对应的到底是哪次请求）；

after在每次方法之后后都会执行，我们在这个方法里记录每次请求耗时；

afterThrowing在抛出异常时才会执行，我们在这个方法里打印error级别的日志;

afterReturn是在方法正常返回时执行，我们在这个方法里打印返回结果。这里这个方法我们对应的是commonPoint切点，即所有方法都会打印返回结果，在实际应用时，可视情况改为对应returnPoint切点，这样只有加了 LogReuslt注解的方法，才会打印返回结果。

最后，需要在spring的配置文件中，添加一行配置：

1. <aop:aspectj-autoproxy proxy-target-class="true"></aop:aspectj-autoproxy>
   

复制代码

注意：这句话应该配置在spring-mvc.xml中扫描完controller包之后。因为我们这里拦截的是controller的方法，在applicationContext中，我们还没有扫描controller类。这里老手对java web,spring框架中各部分的执行顺序了解，更容易理解。新手照着配即可，做多了自然就懂了。

六、运行效果

至此，日志功能已经实现，我们运行一下看下效果：

注意：添加log4j2依赖后，通过maven插件启动时，会有红字提示：严重:Unable to process Jar entry[META-INF/versions/9/module-info.class]from Jar[jar:file:/D:/apache-maven-3.6.1/package/org/apache/logging/log4j/log4j-api/2.11.2/log4j-api-2.11.2.jar!/]for annotations。这是因为maven插件内置的tomcat7.0.47版本过低，但不影响程序正常运行。

maven插件不能修改tomcat版本，而且13年后就停止更新了（这里不知是否是有别的新东西取代所以停更了）。目前，如果因为tomcat版本低等问题导致有错误提示，可以直接下载一个新版本的tomcat，比如前言章节中的7.0.85，使用IDE集成的tomcat启动方式启动，就不会报错了。


小结

本章实现了系统日志的搭建，为我们以后开发调试时快速定位问题打好基础。

源码下载地址：https://idlestudio.ctfile.com/fs/14960372-383747156

本文原文地址：https://www.cnblogs.com/lyosaki88/p/idlewow_5.html

相关阅读：
从零开始实现放置游戏（一）：准备工作
从零开始实现放置游戏（二）：整体框架搭建
从零开始实现放置游戏（三）：后台管理系统搭建
从零开始实现放置游戏（四）后台数值配置的增删查改
从零开始实现放置游戏（五）：管理系统搭建之实现切面日志

作者：丶谦信
博客地址：https://www.cnblogs.com/lyosaki88/p/idlewow_5.html