简介

在项目实际开发过程中，需要统计部分函数的调用耗时，用于协助查找性能问题，并指导部分系统参数配置。

本文通过实现一个这样的示例功能，来展示AOP+SpEL结合带来的巨大好处，同时加深对Spring Expression Language了解

设计目标

只需要通过添加注解的方式，就能快速统计函数调用耗时，同时还能输出更丰富的函数调用上下文信息，使结果具有更大的分析价值。

函数调用上下文包含：

• 函数所属类实例
• 函数入参列表
• 函数调用结果

可以自行添加更多的上下文信息

实现步骤

1. 实现自定义注解
2. 实现SpEL计算接口
3. 实现自定义切面拦截器
4. 为函数添加自定义注解

代码Review

自定义注解

/**
 * @author wurenhai
 * @since 2019/1/11 9:00
 */
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
@Documented
public @interface TimeMeasure {

    /**
     * expression: target=#{#target}, a0=#{#a0}, result=#{#result}
     */
    String value() default "";

}

实现SpEL计算接口

/**
 * @author wurenhai
 * @since 2019/1/11 9:44
 */
public class AspectExpressContext {

    private final EvaluationContext context;
    private final ExpressionParser parser;
    private final ParserContext parserContext;

    private AspectExpressContext() {
        this(null);
    }

    private AspectExpressContext(ApplicationContext applicationContext) {
        StandardEvaluationContext context = new StandardEvaluationContext();
        if (applicationContext != null) {
            context.setBeanResolver(new BeanFactoryResolver(applicationContext));
        }
        SpelParserConfiguration config = new SpelParserConfiguration(true, true);
        this.context = context;
        this.parser = new SpelExpressionParser(config);
        this.parserContext = new TemplateParserContext();
    }

    public AspectExpressContext(Object target, Object[] args, Object result) {
        this();
        context.setVariable("target", target);
        context.setVariable("result", result);
        for (int i = 0; i < args.length; i++) {
            context.setVariable("a" + i, args[i]);
        }
    }

    public String getValue(String express) {
        Expression expression = parser.parseExpression(express, parserContext);
        return expression.getValue(context, String.class);
    }

}

自定义切面拦截器

/**
 * @author wurenhai
 * @since 2019/1/11 9:00
 */
@Aspect
@Component
public class TimeMeasureInterceptor {

    private static final Logger logger = LoggerFactory.getLogger(TimeMeasureInterceptor.class);

    @Around("@annotation(TimeMeasure)")
    public Object around(ProceedingJoinPoint point) throws Throwable {
        StopWatch sw = new StopWatch();
        sw.start();
        Object result = null;
        try {
            result = point.proceed();
            return result;
        } finally {
            sw.stop();
            output(point, result, sw.getLastTaskTimeMillis());
        }
    }

    private void output(ProceedingJoinPoint point, Object result, long timeInMs) {
        String taskName = point.getSignature().getDeclaringType().getSimpleName()
                + "." + point.getSignature().getName() + "()";
        MethodSignature signature = (MethodSignature)point.getSignature();
        TimeMeasure annotation = signature.getMethod().getAnnotation(TimeMeasure.class);
        String expression = annotation.value();

        String text = expression;
        if (StringUtils.hasLength(expression)) {
            AspectExpressContext context = new AspectExpressContext(point.getTarget(), point.getArgs(), result);
            try {
                text = context.getValue(expression);
            } catch (ParseException e) {
                logger.warn("{} parse[{}] error: {}", taskName, expression, e.getMessage());
            } catch (EvaluationException e) {
                logger.warn("{} eval[{}] error: {}", taskName, expression, e.getMessage());
            }
        }

        logger.info("{} cost {}(ms): {}", taskName, timeInMs, text);
    }

}

为函数添加自定义注解

    @SuppressWarnings("MVCPathVariableInspection")
    @TimeMeasure("text1=#{#a0}, text2=#{#a1}, result=#{#result}")
    @GetMapping("/demo/echo")
    @ResponseBody
    public String echo(String text1, String text2) {
        return "ECHO: " + text1 + "," + text2;
    }

参考文档

Spring Expression Language
Aspect Oriented Programming with Spring