Android 函數(shù)耗時(shí)統(tǒng)計(jì)工具之Hugo

Hugo

在前文Android AspectJ詳解中,我們了解了AspectJ的使用場(chǎng)景怠李、特點(diǎn)和基本語(yǔ)法圾叼,這篇將從沃神開(kāi)源的Hugo項(xiàng)目實(shí)戰(zhàn)分析AspectJ的用法,加深對(duì)AspectJ的理解捺癞。

Hugo項(xiàng)目是一個(gè)調(diào)試函數(shù)調(diào)用耗時(shí)的工具夷蚊,通過(guò)對(duì)方法或者類(lèi)添加@DebugLog注解,在運(yùn)行時(shí)會(huì)將函數(shù)的耗時(shí)打印在控制臺(tái)中髓介,通常用于排查函數(shù)耗時(shí)惕鼓,或者用于卡頓檢測(cè)。

我在舊文中分析過(guò)一些卡頓檢測(cè)工具唐础,比如Android卡頓檢測(cè)之BlockCanary箱歧,Matrix系列文章(一) 卡頓分析工具之Trace Canary矾飞,與這兩個(gè)工具不同的是,Hugo需手動(dòng)通過(guò)注解打點(diǎn)呀邢,侵入性較高洒沦,但量級(jí)輕、集成簡(jiǎn)單价淌、不受卡頓閾值限制申眼,適合小項(xiàng)目測(cè)試使用。

使用方法

  1. 項(xiàng)目根目錄build.gradle添加hugo插件依賴
classpath 'com.jakewharton.hugo:hugo-plugin:1.2.1'
  1. 主工程或者library的錄build.gradle中聲明hugo插件蝉衣。
apply plugin: 'com.jakewharton.hugo'

可通過(guò)配置開(kāi)啟或關(guān)閉hugo功能豺型。

hugo {
  enabled false
}
  1. 在類(lèi)或方法上聲明@DebugLog注解。
@DebugLog
public String getName(String first, String last) {
  SystemClock.sleep(15);
  return first + " " + last;
}

運(yùn)行程序會(huì)在控制臺(tái)會(huì)打印函數(shù)耗時(shí)日志:

V/Example: ? getName(first="Wandering", last="Guy")
V/Example: ? getName [16ms] = "Wandering Guy"

可見(jiàn)日志不僅會(huì)打印函數(shù)的耗時(shí) [16ms] 买乃,如果該方法有參數(shù)姻氨,同時(shí)會(huì)把實(shí)參打印出來(lái)。

原理分析

其實(shí)整個(gè)Hugo項(xiàng)目的源碼非常簡(jiǎn)單剪验,也就一百多行代碼肴焊,我們完全可以手?jǐn)]一份。

我們已經(jīng)有了AspectJ的預(yù)備知識(shí)功戚,現(xiàn)在如果讓你實(shí)現(xiàn)一個(gè)Hugo項(xiàng)目娶眷,你會(huì)怎么做呢?三秒思考...


我的思路是這樣的啸臀,既然要統(tǒng)計(jì)方法的耗時(shí)届宠,那需要解決的問(wèn)題主要有兩個(gè):

  1. 如何標(biāo)識(shí)需要統(tǒng)計(jì)耗時(shí)的方法?
  2. 如何統(tǒng)計(jì)方法的耗時(shí)乘粒?

對(duì)于問(wèn)題1 通常的做法就是使用自定義注解標(biāo)識(shí)目標(biāo)方法豌注。

對(duì)于問(wèn)題2 我們這里使用AspectJ完成代碼的織入,由于目標(biāo)是統(tǒng)計(jì)方法的耗時(shí)灯萍,最簡(jiǎn)單的辦法就是在方法執(zhí)行前后各打一點(diǎn)轧铁,然后計(jì)算這個(gè)時(shí)間差,而這里說(shuō)的方法前后打點(diǎn)旦棉,在AspectJ中不就可以用 @Around 注解實(shí)現(xiàn)嗎齿风?bingo!

使用注解需要額外關(guān)注一下保留策略(RetentionPolicy)

這個(gè)屬性有三個(gè)可選值:

  • SOURCE 只保留在源碼中,編譯成class文件后將丟失绑洛。
  • CLASS 保留在class文件中救斑,加載到虛擬機(jī)中將丟棄。
  • RUNTIME 運(yùn)行時(shí)仍保留真屯,可通過(guò)反射獲取注解信息脸候。

所以三者保留范圍的關(guān)系是 RUNTIME > CLASS > SOURCE

如果我們使用AspectJ作為技術(shù)方案,應(yīng)該使用哪種保留策略呢纪他?

CLASS鄙煤,因?yàn)锳spectJ的作用時(shí)機(jī)是在class文件生成后晾匠,因此不能選擇SOURCE茶袒,其次切點(diǎn)pattern支持使用注解作為過(guò)濾條件,這就是說(shuō)在運(yùn)行時(shí)完全用不到注解信息凉馆,因此使用RUNTIME是浪費(fèi)的薪寓。

源碼分析

在Hugo中使用的自定義注解就是@DebugLog。

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

Retention屬性上面已經(jīng)分析過(guò)了澜共,Target表示可以注解在哪些地方向叉,我們要統(tǒng)計(jì)方法的耗時(shí)自然是要注解在方法上,因此需要 METHOD和CONSTRUCTOR 嗦董,為了方便的統(tǒng)計(jì)整個(gè)類(lèi)中所有方法的耗時(shí)母谎,Hugo支持 TYPE

切面代碼是重點(diǎn)京革,定義在了Hugo類(lèi)中奇唤。

@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 {
    ...
  }
 }

切點(diǎn)表達(dá)式比較復(fù)雜,大致分為兩類(lèi)匹摇,一類(lèi)是方法一類(lèi)是構(gòu)造函數(shù)咬扇,滿足其一就可以,對(duì)應(yīng)⑥廊勃。

①處within表達(dá)式聲明的是一個(gè)TypePattern懈贺,也就是類(lèi)型限制,范圍是任意聲明DebugLog注解的類(lèi)型坡垫。

②處使用條件運(yùn)算梭灿,指代任意聲明了DebugLog注解的類(lèi)中所有非內(nèi)部類(lèi)中的方法。再結(jié)合④處冰悠,加上那些被DebugLog注解修飾的任意方法胎源,這樣就構(gòu)成了所有method的范圍。簡(jiǎn)而言之屿脐,也分為兩部分:

  • 所有聲明了DebugLog注解的類(lèi)中所有的方法涕蚤。
  • 所有聲明了DebugLog注解的方法。

切點(diǎn)表達(dá)式中使用了 !synthetic 排除內(nèi)部類(lèi)中的方法 是為了避免再次為內(nèi)部類(lèi)聲明DebugLog注解時(shí)重復(fù)織入的問(wèn)題的诵。

對(duì)于構(gòu)造函數(shù)的切點(diǎn)表達(dá)式万栅,同理。

切點(diǎn)選好了西疤,我們來(lái)看具體織入的代碼烦粒。

@Around("method() || constructor()")
public Object logAndExecute(ProceedingJoinPoint joinPoint) throws Throwable {
    enterMethod(joinPoint);
    //start 打點(diǎn)
    long startNanos = System.nanoTime();
    Object result = joinPoint.proceed();
    //end 打點(diǎn)
    long stopNanos = System.nanoTime();
    //計(jì)算耗時(shí)
    long lengthMillis = TimeUnit.NANOSECONDS.toMillis(stopNanos - startNanos);
    
    exitMethod(joinPoint, result, lengthMillis);
    
    return result;
}

顯然就是在切點(diǎn)代碼 joinPoint.proceed() 前后打上時(shí)間戳。

來(lái)看enterMethod:

private static void enterMethod(JoinPoint joinPoint) {
    if (!enabled) return;

    CodeSignature codeSignature = (CodeSignature) joinPoint.getSignature();

    Class<?> cls = codeSignature.getDeclaringType();
    //獲取方法名
    String methodName = codeSignature.getName();
    //方法參數(shù)列表
    String[] parameterNames = codeSignature.getParameterNames();
    //方法參數(shù)值列表
    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());
    ...
  }

執(zhí)行完enterMethod方法就打印出了類(lèi)似這樣的日志。

V/Example: ? getName(first="Wandering", last="Guy")

再來(lái)看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;
    
    //打印函數(shù)耗時(shí)
    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());
}

這樣就輸出了類(lèi)似這樣的日志:

V/Example: ? getName [16ms] = "Wandering Guy"

總結(jié)

整個(gè)流程分析下來(lái)扰她,并沒(méi)有很復(fù)雜的地方兽掰,我們完全可以借鑒Hugo的思路完成一些常見(jiàn)場(chǎng)景的AOP需求。

我們常用的滬江 aspectjx插件 正是受Hugo項(xiàng)目的影響而設(shè)計(jì)徒役,并在AspectJ的基礎(chǔ)上擴(kuò)展支持AAR, JAR及Kotlin孽尽。

開(kāi)源是神器,吾輩共勉之忧勿!

最后編輯于
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
  • 序言:七十年代末杉女,一起剝皮案震驚了整個(gè)濱河市,隨后出現(xiàn)的幾起案子鸳吸,更是在濱河造成了極大的恐慌熏挎,老刑警劉巖,帶你破解...
    沈念sama閱讀 219,427評(píng)論 6 508
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件晌砾,死亡現(xiàn)場(chǎng)離奇詭異坎拐,居然都是意外死亡,警方通過(guò)查閱死者的電腦和手機(jī)养匈,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 93,551評(píng)論 3 395
  • 文/潘曉璐 我一進(jìn)店門(mén)哼勇,熙熙樓的掌柜王于貴愁眉苦臉地迎上來(lái),“玉大人乖寒,你說(shuō)我怎么就攤上這事猴蹂。” “怎么了楣嘁?”我有些...
    開(kāi)封第一講書(shū)人閱讀 165,747評(píng)論 0 356
  • 文/不壞的土叔 我叫張陵磅轻,是天一觀的道長(zhǎng)。 經(jīng)常有香客問(wèn)我逐虚,道長(zhǎng)聋溜,這世上最難降的妖魔是什么? 我笑而不...
    開(kāi)封第一講書(shū)人閱讀 58,939評(píng)論 1 295
  • 正文 為了忘掉前任叭爱,我火速辦了婚禮撮躁,結(jié)果婚禮上,老公的妹妹穿的比我還像新娘买雾。我一直安慰自己把曼,他們只是感情好,可當(dāng)我...
    茶點(diǎn)故事閱讀 67,955評(píng)論 6 392
  • 文/花漫 我一把揭開(kāi)白布漓穿。 她就那樣靜靜地躺著嗤军,像睡著了一般。 火紅的嫁衣襯著肌膚如雪晃危。 梳的紋絲不亂的頭發(fā)上叙赚,一...
    開(kāi)封第一講書(shū)人閱讀 51,737評(píng)論 1 305
  • 那天老客,我揣著相機(jī)與錄音,去河邊找鬼震叮。 笑死胧砰,一個(gè)胖子當(dāng)著我的面吹牛,可吹牛的內(nèi)容都是我干的苇瓣。 我是一名探鬼主播尉间,決...
    沈念sama閱讀 40,448評(píng)論 3 420
  • 文/蒼蘭香墨 我猛地睜開(kāi)眼钓简,長(zhǎng)吁一口氣:“原來(lái)是場(chǎng)噩夢(mèng)啊……” “哼乌妒!你這毒婦竟也來(lái)了汹想?” 一聲冷哼從身側(cè)響起外邓,我...
    開(kāi)封第一講書(shū)人閱讀 39,352評(píng)論 0 276
  • 序言:老撾萬(wàn)榮一對(duì)情侶失蹤,失蹤者是張志新(化名)和其女友劉穎古掏,沒(méi)想到半個(gè)月后损话,有當(dāng)?shù)厝嗽跇?shù)林里發(fā)現(xiàn)了一具尸體,經(jīng)...
    沈念sama閱讀 45,834評(píng)論 1 317
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡槽唾,尸身上長(zhǎng)有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 37,992評(píng)論 3 338
  • 正文 我和宋清朗相戀三年丧枪,在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片庞萍。...
    茶點(diǎn)故事閱讀 40,133評(píng)論 1 351
  • 序言:一個(gè)原本活蹦亂跳的男人離奇死亡拧烦,死狀恐怖,靈堂內(nèi)的尸體忽然破棺而出钝计,到底是詐尸還是另有隱情恋博,我是刑警寧澤,帶...
    沈念sama閱讀 35,815評(píng)論 5 346
  • 正文 年R本政府宣布私恬,位于F島的核電站债沮,受9級(jí)特大地震影響,放射性物質(zhì)發(fā)生泄漏本鸣。R本人自食惡果不足惜疫衩,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,477評(píng)論 3 331
  • 文/蒙蒙 一、第九天 我趴在偏房一處隱蔽的房頂上張望荣德。 院中可真熱鬧闷煤,春花似錦、人聲如沸涮瞻。這莊子的主人今日做“春日...
    開(kāi)封第一講書(shū)人閱讀 32,022評(píng)論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽(yáng)饲宛。三九已至皆愉,卻和暖如春,著一層夾襖步出監(jiān)牢的瞬間,已是汗流浹背幕庐。 一陣腳步聲響...
    開(kāi)封第一講書(shū)人閱讀 33,147評(píng)論 1 272
  • 我被黑心中介騙來(lái)泰國(guó)打工久锥, 沒(méi)想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留,地道東北人异剥。 一個(gè)月前我還...
    沈念sama閱讀 48,398評(píng)論 3 373
  • 正文 我出身青樓瑟由,卻偏偏與公主長(zhǎng)得像,于是被迫代替她去往敵國(guó)和親冤寿。 傳聞我的和親對(duì)象是個(gè)殘疾皇子歹苦,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 45,077評(píng)論 2 355

推薦閱讀更多精彩內(nèi)容