android语法分析工具,Android 函数耗时统计工具之Hugo
Hugo
在前文Android AspectJ详解中，我们了解了AspectJ的使用场景、特点和基本语法，这篇将从沃神开源的Hugo项目实战分析AspectJ的用法，加深对AspectJ的理解。
Hugo项目是一个调试函数调用耗时的工具，通过对方法或者类添加@DebugLog注解，在运行时会将函数的耗时打印在控制台中，通常用于排查函数耗时，或者用于卡顿检测。
我在旧文中分析过一些卡顿检测工具，比如Android卡顿检测之BlockCanary，Matrix系列文章(一) 卡顿分析工具之Trace Canary，与这两个工具不同的是，Hugo需手动通过注解打点，侵入性较高，但量级轻、集成简单、不受卡顿阈值限制，适合小项目测试使用。
使用方法
项目根目录build.gradle添加hugo插件依赖
classpath 'com.jakewharton.hugo:hugo-plugin:1.2.1'
复制代码主工程或者library的录build.gradle中声明hugo插件。
apply plugin: 'com.jakewharton.hugo'
复制代码
可通过配置开启或关闭hugo功能。
hugo {
enabled false
}
复制代码在类或方法上声明@DebugLog注解。
@DebugLog
public String getName(String first, String last) {
SystemClock.sleep(15);
return first + " " + last;
}
复制代码
运行程序会在控制台会打印函数耗时日志：
V/Example: ⇢ getName(first="Wandering", last="Guy")
V/Example: ⇠ getName [16ms] = "Wandering Guy"
复制代码
可见日志不仅会打印函数的耗时 [16ms] ，如果该方法有参数，同时会把实参打印出来。
原理分析
其实整个Hugo项目的源码非常简单，也就一百多行代码，我们完全可以手撸一份。
我们已经有了AspectJ的预备知识，现在如果让你实现一个Hugo项目，你会怎么做呢？三秒思考...
我的思路是这样的，既然要统计方法的耗时，那需要解决的问题主要有两个：
如何标识需要统计耗时的方法？
如何统计方法的耗时？
对于问题1 通常的做法就是使用自定义注解标识目标方法。
对于问题2 我们这里使用AspectJ完成代码的织入，由于目标是统计方法的耗时，最简单的办法就是在方法执行前后各打一点，然后计算这个时间差，而这里说的方法前后打点，在AspectJ中不就可以用 @Around 注解实现吗？bingo!
使用注解需要额外关注一下保留策略(RetentionPolicy)
这个属性有三个可选值：
SOURCE 只保留在源码中，编译成class文件后将丢失。
CLASS 保留在class文件中，加载到虚拟机中将丢弃。
RUNTIME 运行时仍保留，可通过反射获取注解信息。
所以三者保留范围的关系是 RUNTIME > CLASS > SOURCE。
如果我们使用AspectJ作为技术方案，应该使用哪种保留策略呢？
CLASS，因为AspectJ的作用时机是在class文件生成后，因此不能选择SOURCE，其次切点pattern支持使用注解作为过滤条件，这就是说在运行时完全用不到注解信息，因此使用RUNTIME是浪费的。
源码分析
在Hugo中使用的自定义注解就是@DebugLog。
@Target({TYPE, METHOD, CONSTRUCTOR}) @Retention(CLASS)
public @interface DebugLog {
}
复制代码
Retention属性上面已经分析过了，Target表示可以注解在哪些地方，我们要统计方法的耗时自然是要注解在方法上，因此需要 METHOD和CONSTRUCTOR ，为了方便的统计整个类中所有方法的耗时，Hugo支持 TYPE 。
切面代码是重点，定义在了Hugo类中。
@Aspect
public class Hugo {
//①
@Pointcut("within(@hugo.weaving.DebugLog *)")
public void withinAnnotatedClass() {}
//②
@Pointcut("execution(!synthetic * *(..)) && withinAnnotatedClass()")
public void methodInsideAnnotatedType() {}
//③
@Pointcut("execution(!synthetic *.new(..)) && withinAnnotatedClass()")
public void constructorInsideAnnotatedType() {}
//④
@Pointcut("execution(@hugo.weaving.DebugLog * *(..)) || methodInsideAnnotatedType()")
public void method() {}
//⑤
@Pointcut("execution(@hugo.weaving.DebugLog *.new(..)) || constructorInsideAnnotatedType()")
public void constructor() {}
//⑥
@Around("method() || constructor()")
public Object logAndExecute(ProceedingJoinPoint joinPoint) throws Throwable {
...
}
}
复制代码
切点表达式比较复杂，大致分为两类，一类是方法一类是构造函数，满足其一就可以，对应⑥。
①处within表达式声明的是一个TypePattern，也就是类型限制，范围是任意声明DebugLog注解的类型。
②处使用条件运算，指代任意声明了DebugLog注解的类中所有非内部类中的方法。再结合④处，加上那些被DebugLog注解修饰的任意方法，这样就构成了所有method的范围。简而言之，也分为两部分：
所有声明了DebugLog注解的类中所有的方法。
所有声明了DebugLog注解的方法。
切点表达式中使用了 !synthetic 排除内部类中的方法 是为了避免再次为内部类声明DebugLog注解时重复织入的问题。
对于构造函数的切点表达式，同理。
切点选好了，我们来看具体织入的代码。
@Around("method() || constructor()")
public Object logAndExecute(ProceedingJoinPoint joinPoint) throws Throwable {
enterMethod(joinPoint);
//start 打点
long startNanos = System.nanoTime();
Object result = joinPoint.proceed();
//end 打点
long stopNanos = System.nanoTime();
//计算耗时
long lengthMillis = TimeUnit.NANOSECONDS.toMillis(stopNanos - startNanos);
exitMethod(joinPoint, result, lengthMillis);
return result;
}
复制代码
显然就是在切点代码 joinPoint.proceed() 前后打上时间戳。
来看enterMethod：
private static void enterMethod(JoinPoint joinPoint) {
if (!enabled) return;
CodeSignature codeSignature = (CodeSignature) joinPoint.getSignature();
Class> cls = codeSignature.getDeclaringType();
//获取方法名
String methodName = codeSignature.getName();
//方法参数列表
String[] parameterNames = codeSignature.getParameterNames();
//方法参数值列表
Object[] parameterValues = joinPoint.getArgs();
//字符串拼接
StringBuilder builder = new StringBuilder("\u21E2 ");
builder.append(methodName).append('(');
for (int i = 0; i < parameterValues.length; i++) {
if (i > 0) {
builder.append(", ");
}
builder.append(parameterNames[i]).append('=');
builder.append(Strings.toString(parameterValues[i]));
}
builder.append(')');
if (Looper.myLooper() != Looper.getMainLooper()) {
builder.append(" [Thread:\"").append(Thread.currentThread().getName()).append("\"]");
}
//打印日志
Log.v(asTag(cls), builder.toString());
...
}
复制代码
执行完enterMethod方法就打印出了类似这样的日志。
V/Example: ⇢ getName(first="Wandering", last="Guy")
复制代码
再来看exitMethod：
private static void exitMethod(JoinPoint joinPoint, Object result, long lengthMillis) {
if (!enabled) return;
Signature signature = joinPoint.getSignature();
Class> cls = signature.getDeclaringType();
String methodName = signature.getName();
//判断是否有返回值
boolean hasReturnType = signature instanceof MethodSignature
&& ((MethodSignature) signature).getReturnType() != void.class;
//打印函数耗时
StringBuilder builder = new StringBuilder("\u21E0 ")
.append(methodName)
.append(" [")
.append(lengthMillis)
.append("ms]");
//打印返回值
if (hasReturnType) {
builder.append(" = ");
builder.append(Strings.toString(result));
}
Log.v(asTag(cls), builder.toString());
}
复制代码
这样就输出了类似这样的日志：
V/Example: ⇠ getName [16ms] = "Wandering Guy"
复制代码
总结
整个流程分析下来，并没有很复杂的地方，我们完全可以借鉴Hugo的思路完成一些常见场景的AOP需求。
我们常用的沪江 aspectjx插件 正是受Hugo项目的影响而设计，并在AspectJ的基础上扩展支持AAR, JAR及Kotlin。
开源是神器，吾辈共勉之！