Android function time statistics tool Hugo

Hugo

In the previous detailed explanation of Android AspectJ, we have learned the usage scenarios, features and basic syntax of AspectJ. This article will analyze the use of AspectJ from the Hugo project of Vogod open source, and deepen our understanding of AspectJ.

Hugo project is a tool for debugging function call time. By adding @debuglog annotation to method or class, the time of function is printed in the console at run time. It is usually used to check function time, or for lag detection.

I have analyzed some caton detection tools in previous articles, such as BlockCanary of Android Caton detection, and Matrix series articles (I) Trace Canary of Caton analysis tool. Different from these two tools, Hugo requires manual annotation, which is highly invasive. But light weight, simple integration, not limited by the katon threshold, suitable for small project testing.

Method of use

1. Project root build.gradle adds Hugo plugin dependencies

classpath 'com. Jakewharton. Hugo: Hugo - plugin: 1.2.1'
Copy the code

2. The Hugo plugin is declared in the main project or library record build.gradle.

apply plugin: 'com.jakewharton.hugo'
Copy the code

The Hugo function can be enabled or disabled by configuration.

hugo {
  enabled false
}
Copy the code

3. Declare @debuglog annotations on a class or method.

@DebugLog
public String getName(String first, String last) {
  SystemClock.sleep(15);
  return first + "" + last;
}
Copy the code

Running the program will print a log of the function’s time on the console:

V/Example: ⇢ getName (first ="Wandering", last="Guy"V/Example: ⇠ getName [16ms] ="Wandering Guy"
Copy the code

The visible log not only prints the time of the function [16ms], but also the arguments if the method has any.

The principle of analysis

In fact, the whole Hugo project source code is very simple, also more than 100 lines of code, we can hand copy.

Now that we have a primer on AspectJ, what would you do if you were asked to implement a Hugo project? Three seconds to think…

---

My thinking is as follows: Since we need to count the time consuming of the method, there are two main problems to be solved:

1. How do I identify methods that require time statistics?
2. How to count method time?

A common approach to problem 1 is to use custom annotations to identify the target method.

For question 2, we use AspectJ for code weaving. Since the goal is to count the method’s time, the easiest way is to count the time difference before and after the method is executed. In AspectJ, we can use @around annotations to do this. bingo!

Using annotations requires additional attention to RetentionPolicy.

This property has three optional values:

• The SOURCE remains in the SOURCE code only and is lost when compiled into a class file.
• The CLASS is stored in the CLASS file and discarded when loaded to the VM.
• The RUNTIME RUNTIME is retained and annotation information can be retrieved through reflection.

RUNTIME > CLASS > SOURCE

If we use AspectJ as our technical solution, which retention strategy should we use?

CLASS, because AspectJ acts after the CLASS file is generated, SOURCE cannot be selected. Second, the pattern cut supports the use of annotations as filtering conditions, which means that the annotation information is not needed at RUNTIME, so using the RUNTIME is wasteful.

Source code analysis

The custom annotation used in Hugo is @debuglog.

@Target({TYPE, METHOD, CONSTRUCTOR}) @Retention(CLASS)
public @interface DebugLog {
}
Copy the code

The Retention attribute has been analyzed above, and Target indicates where annotations can be made. Therefore, we need METHOD and CONSTRUCTOR to measure the time consumption of methods, so Hugo supports TYPE in order to conveniently count the time consumption of all methods in the whole class.

The aspect code is the focus, defined in the Hugo class.

@aspect public class Hugo {//"within(@hugo.weaving.DebugLog *)")
  public void withinAnnotatedClass() {} / / (2) the @pointcut ("execution(! synthetic * *(..) ) && withinAnnotatedClass()")
  public void methodInsideAnnotatedType() {} / / (3) the @pointcut ("execution(! synthetic *.new(..) ) && withinAnnotatedClass()")
  public void constructorInsideAnnotatedType() {} / / (4) the @pointcut ("execution(@hugo.weaving.DebugLog * *(..) ) || methodInsideAnnotatedType()")
  public void method() {} / / (5) the @pointcut ("execution(@hugo.weaving.DebugLog *.new(..) ) || constructorInsideAnnotatedType()")
  public void constructor() {} / / 6 @ Around ("method() || constructor()")
  public Object logAndExecute(ProceedingJoinPoint joinPoint) throws Throwable { ... }}Copy the code

Tangent point expression is more complex, roughly divided into two categories, one is the method and the other is the constructor, satisfy one of the can, corresponding to ⑥.

The within expression declares a TypePattern, which is a type constraint. The range is any type of DebugLog annotation that can be declared.

② uses conditional operations to refer to all non-inner class methods in any class that declared DebugLog annotations. Combine that with ④, plus any methods that are DebugLog annotated, and you have the scope of all methods. In short, there are also two parts:

• All methods in classes that declare DebugLog annotations.
• All methods that declare DebugLog annotations.

Used in the tangent expression! The purpose of synthetic is to exclude methods from inner classes to avoid the problem of repeated weaving when DebugLog annotations are declared for inner classes again.

The same is true for the constructor’s pointcut expression.

So with the pointcut chosen, let’s look at the code that’s woven in.

@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 (); / / calculation takes long lengthMillis = TimeUnit. NANOSECONDS. ToMillis (stopNanos - startNanos);exitMethod(joinPoint, result, lengthMillis);
    
    return result;
}
Copy the code

It is obvious to timestamp the pointcut code before and after joinPoint.proceed().

To see enterMethod:

private static void enterMethod(JoinPoint joinPoint) {
    if(! enabled)return; CodeSignature codeSignature = (CodeSignature) joinPoint.getSignature(); Class<? > cls = codeSignature.getDeclaringType(); String methodName = codesignating.getName (); / / method parameter list 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("\]" "); } // Print log.v (asTag(CLS), builder.toString()); . }Copy the code

After the enterMethod method is executed, a log similar to this is printed.

V/Example: ⇢ getName (first ="Wandering", last="Guy")
Copy the code

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]"); // Prints the return valueif (hasReturnType) {
    builder.append("=");
    builder.append(Strings.toString(result));
    }
    
    Log.v(asTag(cls), builder.toString());
}
Copy the code

This produces a log like this:

V/Example: ⇠ getName [16ms] = "Wandering Guy"
Copy the code

conclusion

The whole process analysis, there is no very complicated place, we can learn from Hugo’s ideas to complete some common scenarios of AOP requirements.

Our popular Hujiang AspectJX plugin was inspired by Hugo’s project and extends support for AAR, JAR, and Kotlin on top of AspectJ.

Open source is a miracle, we encourage each other!