spring boot使用AOP統一處理web請求

時間 2019-11-06

標籤 spring boot 使用 aop 統一處理 web 請求欄目 Spring 简体版

原文原文鏈接

爲了保證服務的高可用，及時發現問題，迅速解決問題，爲應用添加log是必不可少的。java

可是隨着項目的增大，方法增多，每一個方法加單獨加日誌處理會有不少冗餘web

那在SpringBoot項目中如何統一的處理Web請求日誌？spring

基本思想：編程

　　採用AOP的方式，攔截請求，寫入日誌json

AOP 是面向切面的編程，就是在運行期經過動態代理的方式對代碼進行加強處理app

基於AOP不會破壞原來程序邏輯，所以它能夠很好的對業務邏輯的各個部分進行隔離，從而使得業務邏輯各部分之間的耦合度下降，提升程序的可重用性，同時提升了開發的效率。dom

1.添加依賴ide

<dependency>
     <groupId>org.springframework.boot</groupId>
     <artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
     <groupId>org.springframework.boot</groupId>
     <artifactId>spring-boot-starter-aop</artifactId>
</dependency>

引入spring-boot-starter-web 依賴以後無需在引入相關的日誌依賴，spring-boot-starter-web中已經集成了slf4j 的依賴
引入spring-boot-starter-aop 依賴以後，AOP 的功能便是啓動狀態spring-boot

2.配置測試

application.properties添加

# AOP
spring.aop.auto=true
spring.aop.proxy-target-class=true

logback-spring.xml，主要是ControllerRequest那部分

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

    <property name="log.path" value="logs" />

    <!--0. 日誌格式和顏色渲染 -->
    <!-- 彩色日誌依賴的渲染類 -->
    <conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter" />
    <conversionRule conversionWord="wex" converterClass="org.springframework.boot.logging.logback.WhitespaceThrowableProxyConverter" />
    <conversionRule conversionWord="wEx" converterClass="org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter" />
    <!-- 彩色日誌格式 -->
    <property name="CONSOLE_LOG_PATTERN" value="${CONSOLE_LOG_PATTERN:-%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>

    <!--1. 輸出到控制檯-->
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <!--此日誌appender是爲開發使用，只配置最底級別，控制檯輸出的日誌級別是大於或等於此級別的日誌信息-->
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>info</level>
        </filter>
        <encoder>
            <Pattern>${CONSOLE_LOG_PATTERN}</Pattern>
            <!-- 設置字符集 -->
            <charset>UTF-8</charset>
        </encoder>
    </appender>

    <!--2. 輸出到文檔-->
    <!-- 2.1 level爲 DEBUG 日誌，時間滾動輸出  -->
    <appender name="DEBUG_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在記錄的日誌文檔的路徑及文檔名 -->
        <file>${log.path}/debug/debug.log</file>
        <!--日誌文檔輸出格式-->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
            <charset>UTF-8</charset> <!-- 設置字符集 -->
        </encoder>
        <!-- 日誌記錄器的滾動策略，按日期，按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 日誌歸檔 -->
            <fileNamePattern>${log.path}/debug/debug-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--日誌文檔保留天數-->
            <maxHistory>15</maxHistory>
        </rollingPolicy>
        <!-- 此日誌文檔只記錄debug級別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>debug</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

    <!-- 2.2 level爲 INFO 日誌，時間滾動輸出  -->
    <appender name="INFO_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在記錄的日誌文檔的路徑及文檔名 -->
        <file>${log.path}/info/info.log</file>
        <!--日誌文檔輸出格式-->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
            <charset>UTF-8</charset>
        </encoder>
        <!-- 日誌記錄器的滾動策略，按日期，按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 天天日誌歸檔路徑以及格式 -->
            <fileNamePattern>${log.path}/info/info-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--日誌文檔保留天數-->
            <maxHistory>15</maxHistory>
        </rollingPolicy>
        <!-- 此日誌文檔只記錄info級別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>info</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

    <!-- 2.3 level爲 WARN 日誌，時間滾動輸出  -->
    <appender name="WARN_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在記錄的日誌文檔的路徑及文檔名 -->
        <file>${log.path}/warn/warn.log</file>
        <!--日誌文檔輸出格式-->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
            <charset>UTF-8</charset> <!-- 此處設置字符集 -->
        </encoder>
        <!-- 日誌記錄器的滾動策略，按日期，按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${log.path}/warn/warn-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--日誌文檔保留天數-->
            <maxHistory>15</maxHistory>
        </rollingPolicy>
        <!-- 此日誌文檔只記錄warn級別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>warn</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

    <!-- 2.4 level爲 ERROR 日誌，時間滾動輸出  -->
    <appender name="ERROR_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在記錄的日誌文檔的路徑及文檔名 -->
        <file>${log.path}/error/error.log</file>
        <!--日誌文檔輸出格式-->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
            <charset>UTF-8</charset> <!-- 此處設置字符集 -->
        </encoder>
        <!-- 日誌記錄器的滾動策略，按日期，按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${log.path}/error/error-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--日誌文檔保留天數-->
            <maxHistory>15</maxHistory>
        </rollingPolicy>
        <!-- 此日誌文檔只記錄ERROR級別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

    <springProfile name="dev">
        <root level="info">
            <appender-ref ref="CONSOLE" />
            <appender-ref ref="DEBUG_FILE" />
            <appender-ref ref="INFO_FILE" />
            <appender-ref ref="WARN_FILE" />
            <appender-ref ref="ERROR_FILE" />
        </root>
    </springProfile>

    <springProfile name="prod">
        <root level="info">
            <appender-ref ref="DEBUG_FILE" />
            <appender-ref ref="INFO_FILE" />
            <appender-ref ref="WARN_FILE" />
            <appender-ref ref="ERROR_FILE" />
        </root>
    </springProfile>

    <appender name="ControllerRequest" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${log.path}/request/info.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <FileNamePattern>${log.path}/request/info.log.%d{yyyy-MM-dd}</FileNamePattern>
            <maxHistory>30</maxHistory>
        </rollingPolicy>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
        </encoder>
    </appender>

    <logger name="ControllerRequest" level="DEBUG" additivity="false">
        <appender-ref ref="ControllerRequest"/>
    </logger>

</configuration>

View Code

3..實現

實現切面的註解

　　（1）類註解

　　　　A. @Aspect 將一個java類定義爲切面類

　　　　B. @order(i) 標記切面類的處理優先級，i值越小，優先級別越高。能夠註解類,也能註解到方法上

　　（2）方法註解

　　　　A. @Pointcut 定義一個切入點，能夠是一個表達式

execution表達式，eg:

任意公共方法的執行
execution(public * *(..)) 

任何一個以「set」開始的方法的執行
execution(* set*(..)) 

定義在controller包裏的任意方法的執行
execution(public * com.example.demo.controller.*(..))  

定義在controller包裏的任意方法的執行
execution(public * com.example.demo.controller.*.*(..))  

定義在controller包和全部子包裏的任意類的任意方法的執行
execution(public * com.example.demo.controller..*.*(..))

　　　　B. 實如今不一樣的位置切入

@Before 在切點前執行方法,內容爲指定的切點

@After 在切點後，return前執行

@AfterReturning 切入點在 return內容以後（可用做處理返回值）

@Around 切入點在先後切入內容，並本身控制什麼時候執行切入的內容

@AfterThrowing 處理當切入部分拋出異常後的邏輯

　　　　C.@order(i) 標記切點的優先級，i越小，優先級越高

@order(i)註解說明

註解類，i值是，值越小，優先級越高

註解方法，分兩種狀況

註解的是 @Before 是i值越小，優先級越高

註解的是 @After或@AfterReturning 中，i值越大，優先級越高

具體實現

package com.example.demo.configure;

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.*;
import org.aspectj.lang.reflect.MethodSignature;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.core.DefaultParameterNameDiscoverer;
import org.springframework.core.ParameterNameDiscoverer;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

import javax.servlet.http.HttpServletRequest;
import java.lang.reflect.Method;
import java.net.InetAddress;
import java.util.HashMap;
import java.util.Map;

@Aspect
@Component
public class WebRequestLogAspect {

    private final Logger loggerController = LoggerFactory.getLogger("ControllerRequest");
    private final Logger logger = LoggerFactory.getLogger(WebRequestLogAspect.class);
    ThreadLocal<Long> startTime = new ThreadLocal<>();
    ThreadLocal<String> beanName = new ThreadLocal<>();
    ThreadLocal<String> user = new ThreadLocal<>();
    ThreadLocal<String> methodName = new ThreadLocal<>();
    ThreadLocal<String> params = new ThreadLocal<>();
    ThreadLocal<String> remoteAddr = new ThreadLocal<>();
    ThreadLocal<String> uri = new ThreadLocal<>();

    private static Map<String, Object> getFieldsName(ProceedingJoinPoint joinPoint) {
        // 參數值
        Object[] args = joinPoint.getArgs();
        ParameterNameDiscoverer pnd = new DefaultParameterNameDiscoverer();
        MethodSignature signature = (MethodSignature) joinPoint.getSignature();
        Method method = signature.getMethod();
        String[] parameterNames = pnd.getParameterNames(method);
        Map<String, Object> paramMap = new HashMap<>(32);
        for (int i = 0; i < parameterNames.length; i++) {
            paramMap.put(parameterNames[i], args[i] + "(" + args[i].getClass().getSimpleName() + ")");
        }
        return paramMap;
    }

    @Pointcut("execution(public * com.example.demo.controller..*.*(..))")
    public void webRequestLog() {
    }

    /**
     * 前置通知，方法調用前被調用
     * @param joinPoint
     */
    @Before("webRequestLog()")
    public void doBefore(JoinPoint joinPoint) {
        try {
            startTime.set(System.currentTimeMillis());
            // 接收到請求，記錄請求內容
            ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
            HttpServletRequest request = attributes.getRequest();
            beanName.set(joinPoint.getSignature().getDeclaringTypeName());
            methodName.set(joinPoint.getSignature().getName());
            uri.set(request.getRequestURI());
            remoteAddr.set(getIpAddr(request));
            user.set((String) request.getSession().getAttribute("user"));
        } catch (Exception e) {
            logger.error("***操做請求日誌記錄失敗doBefore()***", e);
        }
    }

    /**
     * 環繞通知,環繞加強，至關於MethodInterceptor
     * @param thisJoinPoint
     */
    @Around("webRequestLog()")
    public Object proceed(ProceedingJoinPoint thisJoinPoint) throws Throwable {
        Object object = thisJoinPoint.proceed();
        Map<String, Object> fieldsName = getFieldsName(thisJoinPoint);
        params.set(fieldsName.toString());
        return object;
    }

    /**
     * 處理完請求返回內容
     * @param result
     */
    @AfterReturning(returning = "result", pointcut = "webRequestLog()")
    public void doAfterReturning(Object result) {
        try {
            long requestTime = (System.currentTimeMillis() - startTime.get()) / 1000;
            loggerController.info("請求耗時：" + requestTime + ", uri=" + uri.get() + "; beanName=" + beanName.get() + "; remoteAddr=" + remoteAddr.get() + "; user=" + user.get()
                    + "; methodName=" + methodName.get() + "; params=" + params.get() + "; RESPONSE : " + result);

        } catch (Exception e) {
            logger.error("***操做請求日誌記錄失敗doAfterReturning()***", e);
        }
    }

    /**
     * 獲取登陸用戶遠程主機ip地址
     *
     * @param request
     * @return
     */
    private String getIpAddr(HttpServletRequest request) {
        String ip = request.getHeader("x-forwarded-for");
        if (ip == null || ip.length() == 0 || "unknown".equalsIgnoreCase(ip)) {
            ip = request.getHeader("Proxy-Client-IP");
        }
        if (ip == null || ip.length() == 0 || "unknown".equalsIgnoreCase(ip)) {
            ip = request.getHeader("WL-Proxy-Client-IP");
        }
        if (ip == null || ip.length() == 0 || "unknown".equalsIgnoreCase(ip)) {
            ip = request.getRemoteAddr();
            if (ip.equals("127.0.0.1") || ip.equals("0:0:0:0:0:0:0:1")) {
                //根據網卡取本機配置的IP
                InetAddress inet = null;
                try {
                    inet = InetAddress.getLocalHost();
                } catch (Exception e) {
                    e.printStackTrace();
                }
                ip = inet.getHostAddress();
            }
        }
        // 多個代理的狀況，第一個IP爲客戶端真實IP,多個IP按照','分割
        if (ip != null && ip.length() > 15) {
            if (ip.indexOf(",") > 0) {
                ip = ip.substring(0, ip.indexOf(","));
            }
        }
        return ip;
    }

}

4.測試類

package com.example.demo.controller;

import com.alibaba.fastjson.JSONObject;
import com.example.demo.dao.UserRepository;
import com.example.demo.domain.User;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.*;

import java.util.List;
import java.util.Map;

@RestController
public class Demo {

    @RequestMapping (value = "test1")
    public String test1(@RequestParam(defaultValue = "0") Integer id,@RequestParam(defaultValue = "0")String name){

        return id+name;
    }

    @RequestMapping("hello")
    public String hello() {

        return "Hello World!";
    }

    @PostMapping("/updateStatus")
    public Object updateStatus(@RequestBody JSONObject jsonParam) {

        return jsonParam;
    }

}

輸出到logs/request/info.log內容

2019-09-11 13:31:45.729 [http-nio-8080-exec-4] INFO  ControllerRequest - 請求耗時：0, uri=/test1; beanName=com.example.demo.controller.Demo; remoteAddr=172.27.0.17; user=null; methodName=test1; params={name=abcdef(String), id=123(Integer)}; RESPONSE : 123abcdef
2019-09-11 13:32:16.692 [http-nio-8080-exec-5] INFO  ControllerRequest - 請求耗時：0, uri=/updateStatus; beanName=com.example.demo.controller.Demo; remoteAddr=172.27.0.17; user=null; methodName=updateStatus; params={jsonParam={"id":"17","type":3,"status":2}(JSONObject)}; RESPONSE : {"id":"17","type":3,"status":2}
2019-09-11 13:33:32.584 [http-nio-8080-exec-7] INFO  ControllerRequest - 請求耗時：0, uri=/hello; beanName=com.example.demo.controller.Demo; remoteAddr=172.27.0.17; user=null; methodName=hello; params={}; RESPONSE : Hello World!