從零開始實現放置遊戲（五）：管理系統搭建之實現切面日誌

遊資網發表於2019-11-07
遊戲
上一章，我們初步實現了後臺管理系統的增刪查改功能。然而還有很多功能不完善。這一章，我們先把系統日誌搭建起來，不管是生產問題排查，還是方便開發除錯，日誌都是必不可少的核心功能。所謂切面日誌，比如說，我們想把每個方法的入參都記錄日誌，那需要在每個方法裡都寫一行記錄引數的語句，非常繁瑣。所以需要提取出切面“方法執行前”，“方法執行後”等等，然後在這個切面裡進行程式設計，記錄入參的語句只需要寫一次。整體的流程大致如下圖：

從零開始實現放置遊戲（五）：管理系統搭建之實現切面日誌

這裡我們以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;

  3. import org.apache.logging.log4j.ThreadContext;

  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;

  15. public class LogSessionFilter implements Filter {
  16.     @Override
  17.     public void init(FilterConfig filterConfig) throws ServletException {
  18.     }

  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.             }

  27.             chain.doFilter(request, response);
  28.         } finally {
  29.             ThreadContext.remove("sessionId");
  30.         }
  31.     }

  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;

  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;

  20. import javax.servlet.http.HttpServletRequest;
  21. import javax.servlet.http.HttpSession;
  22. import java.util.Date;
  23. import java.util.Random;

  25. @Aspect
  26. @Component
  27. public class LogAspect {

  29.     private final static Logger logger = LogManager.getLogger(LogAspect.class);

  31.     // ..表示包及子包 該方法代表controller層的所有方法
  32.     @Pointcut("execution(public * com.idlewow.rms.controller..*.*(..))")
  33.     public void commonPoint() {
  34.     }

  36.     @Pointcut("@annotation(com.idlewow.rms.support.annotation.LogResult)")
  37.     public void returnPoint() {
  38.     }


  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.         }

  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.     }

  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.     }

  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.     }

  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

相關文章