利用 AOP 列印方法入參、傳回值、描述、耗時

介紹

公司項目有需求想要列印方法的入參和傳回值, 還要求列印方法的說明。

之前都是在方法的第一行手動列印 log, return 之前再列印傳回值, 有多個傳回點時需要出現重複代碼, 有太多非業務代碼顯得淩亂。

後來采用 AOP 配置自定義 @Log 注解實作了此功能(主要是用于設定方法說明), 包括方法耗時統計。方法的入參和傳回值都采用 fastjson 序列化。現貼出來, 一來給自己做個記錄, 二來分享供大家參考指正。

依賴

<dependency>
    <groupId>com.alibaba</groupId>
    <artifactId>fastjson</artifactId>
</dependency>
<dependency>
    <groupId>org.aspectj</groupId>
    <artifactId>aspectjweaver</artifactId>
</dependency>
<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-context</artifactId>
</dependency>
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
</dependency>
           

注解

package com.ecej.esmart.core.annotation;

import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

/**
 * Created by junbaor on 2017/5/12.
 */
@Target({ElementType.TYPE, ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
public @interface Log {

    /**
     * log 說明
     *
     * @return
     */
    String value() default "";

    /**
     * 是否忽略,比如類上面加的有注解,類中某一個方法不想列印可以設定該屬性為 true
     *
     * @return
     */
    boolean ignore() default false;
}
           

實作

package com.ecej.esmart.core.common;

import com.alibaba.fastjson.JSONObject;
import com.alibaba.fastjson.serializer.SerializerFeature;
import com.ecej.esmart.core.annotation.Log;
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.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;

import java.lang.reflect.Method;

/**
 * Created by junbaor on 2017/5/12.
 */
@Aspect
@Order(100)
@Component
public class LogAspect {

    private static final Logger log = LoggerFactory.getLogger(LogAspect.class);
    private static final String dateFormat = "yyyy-MM-dd HH:mm:ss";
    private static final String STRING_START = "\n>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>\n";
    private static final String STRING_END = "\n<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<\n";

    @Pointcut("execution(* com.ecej.esmart..service.impl..*(..)) || execution(* com.ecej.esmart.http.controller..*(..))")
    public void serviceLog() {
    }

    @Around("serviceLog()")
    public Object around(ProceedingJoinPoint joinPoint) {
        try {
            MethodSignature signature = (MethodSignature) joinPoint.getSignature();
            Method method = signature.getMethod();
            Class<?> targetClass = method.getDeclaringClass();

            StringBuffer classAndMethod = new StringBuffer();

            Log classAnnotation = targetClass.getAnnotation(Log.class);
            Log methodAnnotation = method.getAnnotation(Log.class);

            if (classAnnotation != null) {
                if (classAnnotation.ignore()) {
                    return joinPoint.proceed();
                }
                classAndMethod.append(classAnnotation.value()).append("-");
            }

            if (methodAnnotation != null) {
                if (methodAnnotation.ignore()) {
                    return joinPoint.proceed();
                }
                classAndMethod.append(methodAnnotation.value());
            }

            String target = targetClass.getName() + "#" + method.getName();
            String params = JSONObject.toJSONStringWithDateFormat(joinPoint.getArgs(), dateFormat, SerializerFeature.WriteMapNullValue);

            log.info(STRING_START + "{} 開始調用--> {} 參數:{}", classAndMethod.toString(), target, params);

            long start = System.currentTimeMillis();
            Object result = joinPoint.proceed();
            long timeConsuming = System.currentTimeMillis() - start;

            log.info("\n{} 調用結束<-- {} 傳回值:{} 耗時:{}ms" + STRING_END, classAndMethod.toString(), target, JSONObject.toJSONStringWithDateFormat(result, dateFormat, SerializerFeature.WriteMapNullValue), timeConsuming);
            return result;
        } catch (Throwable throwable) {
            log.error(throwable.getMessage(), throwable);
        }
        return null;
    }

}
           

測試

TestService.java

package com.ecej.esmart.gateway.service.impl;

import com.ecej.esmart.core.annotation.Log;
import com.ecej.esmart.gateway.dto.input.commonpo.Apply;
import org.springframework.stereotype.Service;

@Service
@Log("測試服務")
public class TestService {

    @Log("回聲方法")
    public Apply echo(Apply apply) throws InterruptedException {
        Thread.sleep(500);
        return apply;
    }
}
           

JunitTestService.java

@Autowired
private TestService testService;


@Test
public void init() throws InterruptedException {
    Apply apply = new Apply();
    apply.setEmpId(101);
    apply.setOrderId(9512548);
    apply.setPhone("18011217376");
    apply.setAppointmentTime(new Date());
    System.out.println(testService.echo(apply));
}
           

日志效果：

[20171116 11:00:32.692] | [INFO] | [DESKTOP-MDJIPJH] | [main] | [com.ecej.esmart.core.common.LogAspect] | [--> 
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
測試服務-回聲方法 開始調用--> com.ecej.esmart.gateway.service.impl.TestService#echo 參數:[{"appointmentTime":"2017-11-16 11:00:32","empId":101,"orderId":9512548,"phone":"18011217376","platform":"EMP"}]
[20171116 11:00:33.214] | [INFO] | [DESKTOP-MDJIPJH] | [main] | [com.ecej.esmart.core.common.LogAspect] | [--> 
測試服務-回聲方法 調用結束<-- com.ecej.esmart.gateway.service.impl.TestService#echo 傳回值:{"appointmentTime":"2017-11-16 11:00:32","empId":101,"orderId":9512548,"phone":"18011217376","platform":"EMP"} 耗時:521ms
<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<