面向切面編程-日志切面應用及MDC使用


簡介:

  AOP:面向切面編程,即拓展功能不通過修改源代碼實現,采用橫向抽取機制,取代了傳統的縱向繼承體系重復性代碼。在運行期通過代理方式向目標類織入增強代碼。

  Aspecj:Aspecj 是一個基於java語言的AOP框架,spring2.0開始,spring AOP引入對Aspect的支持,Aspect擴展了Java語言,提供了一個專門的編譯器,在編譯時提供橫向代碼的織入。

  使用aspectj實現aop有兩種方式
    (1)基於aspectj的xml配置
    (2)基於aspectj的注解方式

Spring AOP底層代理機制:

1、JDK動態代理:針對實現了接口的類產生代理

2、CGLib動態代理:針對沒有實現接口的類產生代理,應用的是底層的字節碼增強技術來生成當前類的子類對象。

 

面向切面相關術語:

  JoinPoint(連接點):能被攔截的點,即類里面可以被增強的方法,這些方法稱為連接點,Spring只支持方法類型的連接點。

  PointCut(切入點):實際對JoinPoint中攔截的點,即實際增強的方法成為切入點。

  Advice(通知/增強):所謂增強是指攔截到JoinPoint之后所要做的事情。(比如擴展的日志功能就是增強),通知分為:

    前置增強@Before:在方法(切入點)之前執行的增強

    后置增強@After:在方法(切入點)之后執行的增強

    異常增強@AfterThrowing:在方法執行出現異常的時候執行的增強

    //最終增強:在后置通知之后執行,無論目標方法是否出現異常,都會執行的增強,好像沒有這個

    環繞增強@Around:在方法之前和之后都執行的增強

    返回增強@AfterReturning:在方法正常返回之后執行

  Aspect(切面):切入點和增強的結合,即將通知應用到具體方法上的過程

  Introduction(引介):引介是一種特殊的通知在不修改類代碼的前提下, Introduction 可以在運行期為類動態地添加一些方法或 Field.(一般不用)

  Target(目標對象):代理的目標對象,即要增強的類

  Weaving(織入):是指把增強應用到目標對象來創建新的代理對象的過程

  Proxy( 代理) :一個類被 AOP 織入增強后, 就產生一個結果代理類

   

實踐:

  導入aop相關的包

<!--注解和aop的jar包-->
<dependency>
  <groupId>org.springframework</groupId>
  <artifactId>spring-aop</artifactId>
  <version>4.2.5.RELEASE</version>
</dependency>
<dependency>
  <groupId>aopalliance</groupId>
  <artifactId>aopalliance</artifactId>
  <version>1.0</version>
</dependency>
<dependency>
  <groupId>org.aspectj</groupId>
  <artifactId>aspectjweaver</artifactId>
  <version>1.8.0</version>
</dependency>
<dependency>
  <groupId>org.springframework</groupId>
  <artifactId>spring-aspects</artifactId>
  <version>4.2.5.RELEASE</version>
</dependency>

Spring核心配置文件導入AOP約束

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xmlns:context="http://www.springframework.org/schema/context"
       xmlns:aop="http://www.springframework.org/schema/aop"
       xsi:schemaLocation="
        http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans.xsd
        http://www.springframework.org/schema/context http://www.springframework.org/schema/context/spring-context.xsd
        http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop.xsd">
</beans>

通過execution函數,可以定義切點的方法切入
語法:
  execution(<訪問修飾符>?<返回類型><方法名>(<參數>)<異常>)
例如:
1、匹配所有類public方法 execution(public * * (..))
2、匹配指定包下所有類中的方法 execution(* cn.com.yang.dao.*(..)) 不包含子包
execution(* cn.com.yang.dao..*(..)) 包含本包,子孫包下的所有類
3、匹配指定類所有方法 execution(* cn.com.yang.dao.UserDao*(..) )
4、匹配實現特定接口所有類中的方法 execution(* cn.com.yang.dao.GenericDao+.*(..))
5、匹配所有save開頭的方法 execution(* save*(..))
6、所有方法 execution(* * . *(..))

 

基於XML的AOP:

aop增強類:

/**
 * aop增強類
 */
public class MyUserAop {
    //前置通知
    public void before1() {
        System.out.println("前置增強......");
    }
    //后置通知
    public void after1() {
        System.out.println("后置增強......");
    }

    //環繞通知
    public void around1(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        //方法之前
        System.out.println("方法之前.....");

        //執行被增強的方法
        proceedingJoinPoint.proceed();

        //方法之后
        System.out.println("方法之后.....");
    }
}

切入點,即實際要增強的方法:

// User實體的add方法
public void add(){
    System.out.println("user的add方法");
}

Spring配置文件中的配置

<!--裝配aop增強類-->
<bean id="myUserAop" class="cn.com.yang.common.MyUserAop"/>

<aop:config>
    <!--定義切入點-->
    <aop:pointcut id="pointcut1" expression="execution(* cn.com.yang.modules.base.model.User.add(..))"/>
    <!--定義切面-->
    <aop:aspect ref="myUserAop" order="1">
        <aop:before method="before1" pointcut-ref="pointcut1"/>
        <aop:after method="after1" pointcut-ref="pointcut1"/>
    </aop:aspect>
</aop:config>

輸出結果:

  前置增強......
  user的add方法
  后置增強......

 

基於AspectJ注解的AOP:

1、在Spring核心配置文件中配置,開啟AOP掃描

<!--
開啟aop掃描
自動為spring容器中那些配置@aspectJ切面的bean創建代理,織入切面。當然,spring
在內部依舊采用AnnotationAwareAspectJAutoProxyCreator進行自動代理的創建工作,但具體實現的細節已經被<aop:aspectj-autoproxy />隱藏起來了
<aop:aspectj-autoproxy />有一個proxy-target-class屬性,默認為false,表示使用jdk動態代理織入增強,當配為<aop:aspectj-autoproxy  poxy-target-class="true"/>時,
表示使用CGLib動態代理技術織入增強。不過即使proxy-target-class設置為false,如果目標類沒有聲明接口,則spring將自動使用CGLib動態代理。
-->
<aop:aspectj-autoproxy/>

<!--aop增強類-->
<bean id="myUserAop" class="cn.com.yang.common.MyUserAop"/>
2、在增強類上面使用注解@Aspect
3、在增強類的方法上使用注解配置切入點表達式
配置之后的增強類:
/**
 * aop增強類
 */
@Aspect
public class MyUserAop {
    //前置通知
    @Before(value = "execution(* cn.com.yang.modules.base.model.User.*(..))")
    public void before1() {
        System.out.println("前置增強......");
    }
    //后置通知
    @After(value = "execution(* cn.com.yang.modules.base.model.User.*(..))")
    public void after1() {
        System.out.println("后置增強......");
    }

    //環繞通知
    @Around(value = "execution(* cn.com.yang.modules.base.model.User.*(..))")
    public void around1(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        //方法之前
        System.out.println("方法之前.....");

        //執行被增強的方法
        proceedingJoinPoint.proceed();

        //方法之后
        System.out.println("方法之后.....");
    }
}
執行結果:
  方法之前.....
  前置增強......
  user的add方法
  方法之后.....
  后置增強......

 

AOP應用:

  在實際的應用中,每個方法內邏輯處理前可能都要打印入參信息,方法執行結束再打印返回結果。那么就可以使用AOP的橫向抽取機制,為所有的方法增強前置日志輸出和后置日志輸出。

下面是一個實際項目中的使用自定義注解和AOP實現的環繞增強打印入參和響應結果日志和在返回結果為sucess的情況下將日志信息入庫的例子:

自定義日志注解:

/**
 * 日志注解,不需要入庫的則不加本注解(返回值中responseCode為"0000"才會入庫)
 * value:需要記錄到數據庫中的操作信息,如:@Log("刪除渠道:{channelId}"),其中channelId為請求參數中的值,
 *      沒有占位符則直接記錄value值,目前只支持入庫傳入參數中的值
 * ElementType.METHOD 此注解只可應用在方法上,因為Spring只能對方法增強
 * RetentionPolicy.RUNTIME 此注解在運行期仍保留,所以可在運行期使用代理獲取有此注解的方法
 * Documented 此注解包含在JavaDoc中
 */
@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
@Documented
public @interface Log {
    String value() default "";
}

 注意:若增強的方法位於controller層,那么在springmvc的配置文件中必須加上<aop:aspectj-autoproxy/>配置開啟AOP自動自動代理。

  如果service層或者其他地方也需要增強,那么在Spring的配置文件中也要加上<aop:aspectj-autoproxy/>配置開啟AOP自動自動代理。

  另外,spring的bean掃描和springMvc的bean掃描要分開,分別在各自的配置文件中配置。

日志增強類:

package com.suning.epp.maarms.release.monitor;

import com.alibaba.fastjson.JSON;
import com.alibaba.fastjson.JSONObject;
import com.alibaba.fastjson.serializer.PropertyFilter;
import com.alibaba.fastjson.serializer.SerializerFeature;
import com.suning.epp.maarms.common.constants.Constants;
import com.suning.epp.maarms.common.utils.StringUtil;
import com.suning.epp.maarms.release.service.intf.OperateLogService;
import com.suning.epp.pu.common.aop.lang.CommonResult;
import org.apache.commons.lang3.StringUtils;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.aspectj.lang.reflect.MethodSignature;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

import javax.annotation.Resource;
import javax.servlet.http.HttpServletRequest;
import java.lang.reflect.Method;
import java.util.Arrays;
import java.util.Enumeration;
import java.util.HashMap;
import java.util.Map;
import java.util.regex.Matcher;
import java.util.regex.Pattern;

/**
 * 日志切面,切controller方法,記錄方法調用、退出與調用時間,如果有responseCode也會記錄調用結果日志,<br/>
 * 如果加了@Log注解,會將操作記錄加到數據庫
 *
 * @author 17111829
 */
@Aspect
@Component
public class LogAdvice {

    private static final Logger LOGGER = LoggerFactory.getLogger(LogAdvice.class);

    /**
     * 日志文件中配置的線程號占位符
     */
    private static final String STR_INVOKE_NO = "invokeNo";

    private static final Pattern PATTERN = Pattern.compile("\\{[^{]*}");

    private static final String LEFT_BRACE = "{";

    /**
     * @Resource 默認按照bean id名稱進行注入依賴
     * 日志入庫服務
     */
    @Resource
    private OperateLogService operateLogService;

    /**
     * 抽取工作的切入點表達式,切點,所有含有@RequestMapping的方法
     */
    @Pointcut("@annotation(org.springframework.web.bind.annotation.RequestMapping)")
    private void webPointcut() {
        // Do nothing
    }

    /**
     * 在方法執行前后增強
     *
     * @param joinPoint joinPoint
     * @return 方法返回值
     */
    @Around("webPointcut()")
    public Object around(ProceedingJoinPoint joinPoint) {
        MDC.put(STR_INVOKE_NO, StringUtil.getUuid());
        // 記錄整個方法的執行用時
        long start = System.currentTimeMillis();
        // 獲取當前方法執行的上下文的request
        HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes())
                .getRequest();
        String requestURI = request.getRequestURI();
        // 獲取請求發起操作人
        String userId = request.getRemoteUser();
        // 獲取請求參數
        Map<String, Object> paramMap = getRequestParams(request);
        // 不輸出map中字段值為null的字段
        String requestParams = JSONObject.toJSONString(paramMap, SerializerFeature.WriteMapNullValue);
        // 打印入參日志
        LOGGER.info("URI:{},用戶:{}, 入參:{}", requestURI, userId, requestParams);
        // 獲取被增強的方法的相關信息
        MethodSignature ms = (MethodSignature) joinPoint.getSignature();
        // 獲取被增強的方法
        Method pointcutMethod = ms.getMethod();
        // @Log注解的value屬性值
        String logContent = null;
        // 判斷被增強的方法上是否有@Log注解
        if (pointcutMethod.isAnnotationPresent(Log.class)) {
            Log logAnon = pointcutMethod.getAnnotation(Log.class);
            logContent = logAnon.value();
        }

        Object result = null;
        try {
            // 執行被增強的方法並獲取方法的返回值
            result = joinPoint.proceed();
            String responseCode = null;
            String resultStr;
            // 如果返回的結果是個字符串
            if (result instanceof String) {
                resultStr = (String) result;
                // 如果有@Log注解並且@Log注解的value不為空
                if (StringUtils.isNotBlank(logContent)) {
                    JSONObject jso = JSON.parseObject(resultStr);
                    responseCode = jso.getString(Constants.RESPONSE_CODE);
                }
                // 方法執行返回的結果不是字符串
            } else {
                // 如果方法的返回值一個分頁查詢的結果
                if (result instanceof PageResult) {
                    // 分頁數據過濾掉 data,不打印日志,SerializerFeature.WriteMapNullValue不輸出Map中為null的字段
                    resultStr = JSON.toJSONString(result, dataFilter, SerializerFeature.WriteMapNullValue);
                } else {
                    resultStr = JSON.toJSONString(result, SerializerFeature.WriteMapNullValue);
                }
                // 有@Log注解時,如果返回0000則記錄操作日志
                if (StringUtils.isNotBlank(logContent)) {
                    if (result instanceof Map) {
                        responseCode = (String) ((Map) result).get(Constants.RESPONSE_CODE);
                    } else if (result instanceof CommonResult) {
                        responseCode = ((CommonResult) result).getResponseCode();
                    }
                }
            }
            // 返回0000則記錄操作日志
            if ("0000".equals(responseCode)) {
                insertOperateLog(logContent, userId, paramMap);
            }

            long end = System.currentTimeMillis();
            long useTime = end - start;
            LOGGER.info("用時:{}ms,返回結果:{}", useTime, resultStr);
      // 被增強的方法的異常也再此捕獲,因此在代碼中將不需要捕獲異常信息 }
catch (Throwable throwable) { LOGGER.error("發生異常, 異常信息:{}", ExceptionUtil.getAllStackTrace(throwable)); } // 方法執行結束,移除上下文中的線程號 MDC.remove(STR_INVOKE_NO); return result; } /** * 獲取請求參數 * * @param request request * @return json格式參數 */ private Map<String, Object> getRequestParams(HttpServletRequest request) { Enumeration pNames = request.getParameterNames(); Map<String, Object> paramMap = new HashMap<>(6); String paramName; String[] paramValues; while (pNames.hasMoreElements()) { paramName = String.valueOf(pNames.nextElement()); paramValues = request.getParameterValues(paramName); if (paramValues != null && paramValues.length == 1) { paramMap.put(paramName, paramValues[0]); } else { paramMap.put(paramName, paramValues); } } return paramMap; } /** * 日志入庫 * * @param logContent 操作事件 */ private void insertOperateLog(String logContent, String userId, Map<String, Object> paramMap) { if (StringUtils.isNotBlank(logContent)) { String newLogContent = logContent; // 如果有占位符則替換 if (logContent.contains(LEFT_BRACE) && paramMap != null) { newLogContent = replaceParam(logContent, paramMap); } // 入庫,誰干了什么 operateLogService.insertOperateLog(userId, newLogContent); } } /** * 用入參中的值 替換@Log注解中的占位符 * * @param logContent @Log注解中的value值 * @return 替換后的操作內容 */ private String replaceParam(String logContent, Map<String, Object> paramMap) { Matcher matcher = PATTERN.matcher(logContent); String matchedStr; String oldContent; Object newContent; String newLogContent = logContent; while (matcher.find()) { matchedStr = matcher.group(); oldContent = matchedStr.substring(1, matchedStr.length() - 1).trim(); newContent = paramMap.get(oldContent); if (newContent != null) { if (newContent instanceof String[]) { newLogContent = newLogContent.replace(matchedStr, Arrays.toString((String[]) newContent)); } else { newLogContent = newLogContent.replace(matchedStr, newContent.toString()); } } } return newLogContent; } /** * 字段過濾器,過濾掉data字段不打印 */ private PropertyFilter dataFilter = new PropertyFilter() { @Override public boolean apply(Object object, String name, Object value) { // false表示 data字段將被排除在外 return !"data".equals(name); } }; }

 為HTTP請求加上線程號方便日志追蹤

/**
 * 為每一個的HTTP請求添加線程號
 *
 * @author yangyongjie
 * @date 2019/9/2
 * @desc
 */
@Aspect
@Component
public class LogAspect {

    private static final String STR_THREAD_ID = "threadId";

    @Pointcut(value = "@annotation(org.springframework.web.bind.annotation.RequestMapping)")
    private void webPointcut() {
        // doNothing
    }

    /**
     * 為所有的HTTP請求添加線程號
     *
     * @param joinPoint
     * @throws Throwable
     */
    @Around(value = "webPointcut()")
    public void around(ProceedingJoinPoint joinPoint) throws Throwable {
        // 方法執行前加上線程號
        MDC.put(STR_THREAD_ID, UUID.randomUUID().toString().replaceAll("-", ""));
        // 執行攔截的方法
        joinPoint.proceed();
        // 方法執行結束移除線程號
        MDC.remove(STR_THREAD_ID);
    }
}

同時攔截多個注解的切點:

 @Pointcut(value = "@annotation(org.springframework.web.bind.annotation.RequestMapping)||@annotation(org.springframework.web.bind.annotation.PostMapping)||@annotation(org.springframework.web.bind.annotation.GetMapping)")
    private void webPointcut() {
        // doNothing
    }

 

其他的一些補充:

1、獲取增強的類的全路徑
    String targetName = joinPoint.getTarget().getClass().getName();
通過全路徑可以獲取到被增強的類的Class對象
    Class targetClass=Class.forName(targetName);
獲取Spring容器中的對象
    Object obj=ApplicationContext.getBean(targetClass);
被增強類的所有方法
    Method[] method = targetClass.getMethods();
2、獲取切點(被增強的方法)
       String methodName = joinPoint.getSignature().getName();
3、獲取被增強的方法的入參
       Object[] arguments = joinPoint.getArgs();

 

 

MDC

  MDC(Mapped Diagnostic Contexts),翻譯過來就是:映射的診斷上下文。意思是:在日志中(映射的)請求ID(requestId),可以作為我們定位(診斷)問題的關鍵字(上下文)。

  有了MDC工具,只要在接口或切面植入 put 和 remove 代碼,就可以在定位問題時,根據映射的唯一 requestID 快速過濾出某次請求的所有日志。

  slf4j的MDC機制其內部基於ThreadLocal實現,可參見Java基礎下的 ThreadLocal這篇博客,https://www.cnblogs.com/yangyongjie/p/10574591.html。所以我們調用 MDC.put()方法傳入

  的請求ID只在當前線程有效。所以,主線程中設置的MDC數據,在其子線程(線程池)中是無法獲取的。那么主線程如何將MDC數據傳遞給子線程? 

  官方建議

    1、在父線程新建子線程之前調用MDC.getCopyOfContextMap()方法將MDC內容取出來傳給子線程

    2、子線程在執行操作前先調用MDC.setContextMap()方法將父線程的MDC內容設置到子線程 

    

示例:

  使用裝飾器模式,對Runnable接口進行一層裝飾,在創建MDCRunnable類對Runnable接口進行一層裝飾。

在創建MDCRunnable類時保存當前線程的MDC值,再執行run()方法

  1):裝飾Runnable

import org.slf4j.MDC;

import java.util.Map;

/**
 * 裝飾器模式裝飾Runnable,傳遞父線程的線程號
 *
 * @author yangyongjie
 * @date 2020/3/9
 * @desc
 */
public class MDCRunnable implements Runnable {

    private Runnable runnable;

    /**
     * 保存當前主線程的MDC值
     */
    private final Map<String, String> mainMdcMap;

    public MDCRunnable(Runnable runnable) {
        this.runnable = runnable;
        this.mainMdcMap = MDC.getCopyOfContextMap();
    }

    @Override
    public void run() {
        // 將父線程的MDC值賦給子線程
        for (Map.Entry<String, String> entry : mainMdcMap.entrySet()) {
            MDC.put(entry.getKey(), entry.getValue());
        }
        // 執行被裝飾的線程run方法
        runnable.run();
        // 執行結束移除MDC值
        for (Map.Entry<String, String> entry : mainMdcMap.entrySet()) {
            MDC.put(entry.getKey(), entry.getValue());
        }
    }

}

 

  然后使用MDCRunnable裝飾類裝飾Runnable

     // 異步線程打印日志,用MDCRunnable裝飾Runnable
        new Thread(new MDCRunnable(new Runnable() {
            @Override
            public void run() {
                logger.debug("log in other thread");
            }
        })).start();

        // 異步線程池打印日志,用MDCRunnable裝飾Runnable
        EXECUTORS.execute(new MDCRunnable(new Runnable() {
            @Override
            public void run() {
                logger.debug("log in other thread pool");
            }
        }));
        EXECUTOR.shutdown();

 

  2)裝飾ThreadPoolExecutor線程池

/**
 *  裝飾ThreadPoolExecutor,將父線程的MDC內容傳給子線程
 * @author yangyongjie
 * @date 2020/3/19
 * @desc
 */
public class MDCThreadPoolExecutor extends ThreadPoolExecutor {

    private static final Logger LOGGER= LoggerFactory.getLogger(MDCThreadPoolExecutor.class);

    public MDCThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit, BlockingQueue<Runnable> workQueue, ThreadFactory threadFactory, RejectedExecutionHandler handler) {
        super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue, threadFactory, handler);
    }

    @Override
    public void execute(final Runnable runnable) {
        // 獲取父線程MDC中的內容,必須在run方法之前,否則等異步線程執行的時候有可能MDC里面的值已經被清空了,這個時候就會返回null
        final Map<String, String> context = MDC.getCopyOfContextMap();
        super.execute(new Runnable() {
            @Override
            public void run() {
                // 將父線程的MDC內容傳給子線程
                MDC.setContextMap(context);
                try {
                    // 執行異步操作
                    runnable.run();
                } finally {
                    // 清空MDC內容
                    MDC.clear();
                }
            }
        });
    }
}

 

  使用:

        private static final MDCThreadPoolExecutor MDCEXECUTORS=new MDCThreadPoolExecutor(1,10,60,TimeUnit.SECONDS,new LinkedBlockingQueue<Runnable>(600), new CustomThreadFactory("mdcThreadPoolTest"), new RejectedExecutionHandler() {
            @Override
            public void rejectedExecution(Runnable r, ThreadPoolExecutor executor) {
                // 打印日志,並且重啟一個線程執行被拒絕的任務
                LOGGER.error("Task:{},rejected from:{}", r.toString(), executor.toString());
                // 直接執行被拒絕的任務,JVM另起線程執行
                r.run();
            }
        });

        LOGGER.info("父線程日志");
        MDCEXECUTORS.execute(new Runnable() {
            @Override
            public void run() {
                LOGGER.info("子線程日志");
            }
        });

  驗證結果父子線程號一致:

[INFO ]2020-03-19 12:42:19.265[main]9454b4b3066c4150b6918cd6ac5584b8[com.xiaomi.mitv.admin.task.AutoRenewCheckTask:76] - 父線程日志
[INFO ]2020-03-19 12:42:21.610[From CustomThreadFactory-mdcThreadPoolTest-worker-1]9454b4b3066c4150b6918cd6ac5584b8[com.xiaomi.mitv.admin.task.AutoRenewCheckTask:80] - 子線程日志

 


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM