ASM实战统计方法耗时

先上demo地址：https://github.com/JeasonWong/CostTime

需求

实际业务开发中有很多需要不改变原业务代码，而需额外增加一些包括各种统计的需求，如APM、无数据埋点等，也就是耳熟能详的AOP，本文以统计方法耗时为例，不使用Aspectj，采用原生态的方式进行实践。

使用者所需要做的就是对所需要统计耗时的方法头部加指定注解@Cost就可以使用了。

目标

  • 不影响现有逻辑

  • 需要统计耗时的方法头部加上注解

  • 支持混淆

方案

方案分两部分，一部分针对JVM，一部分针对Android平台。

JVM

  • 自定义注解

  • 使用ASM增加字节码

  • 反射实例化

  • 使用Instrumentation构建代理

Android

  • gradle plugin 自定义Transform Api

实践

先让我们的方案能在JVM上运行起来。

自定义注解

@Target(ElementType.METHOD)
public @interface Cost {
}

我们先只对方法进行耗时统计，因此Target设为Method。

使用ASM增加字节码

首先自定义一个ClassVisitor，然后重载visitMethod方法，这样我们便可以遍历所有类文件的方法了，然后利用AdviceAdapter类来重新实例化一个MethodVisitor，并且重载它的visitAnnotation、onMethodEnter、onMethodExit方法，其中含义就如方法名一样简单明了。

然后我们通过visitAnnotation方法来判断当前方法注解是否为我们自定义的注解，如果是指定注解，则插入代码，具体插入代码的内容我们接下来再讲，自定义ClassVisitor的代码如下：

public class CostClassVisitor extends ClassVisitor {

    public CostClassVisitor(ClassVisitor classVisitor) {
        super(Opcodes.ASM5, classVisitor);
    }

    @Override
    public MethodVisitor visitMethod(int access, String name, String desc, String signature, String[] exceptions) {
        MethodVisitor mv = cv.visitMethod(access, name, desc, signature, exceptions);
        mv = new AdviceAdapter(Opcodes.ASM5, mv, access, name, desc) {

            private boolean inject = false;

            @Override
            public AnnotationVisitor visitAnnotation(String desc, boolean visible) {
                if (Type.getDescriptor(Cost.class).equals(desc)) {
                    inject = true;
                }
                return super.visitAnnotation(desc, visible);
            }

            @Override
            protected void onMethodEnter() {
                if (inject) {
                    //坐等插代码
                }
            }

            @Override
            protected void onMethodExit(int opcode) {
                if (inject) {
                    //坐等插代码
                }
            }
        };
        return mv;
    }
}

再写ASM插入代码前，我们必须意识到一件事，那就是得知道我们会在onMethodEnter中存一个方法开始时间，再在onMethodExit中存一个方法结束时间，再去相减，那么问题来了，这个时间我们存哪呢？肯定不能是局部变量，因为两个方法间并不会共享局部变量，那么本文是将变量存为静态，方便不同方法间调用，具体可见TimeCache.java，代码比较简单，不多加介绍：

public class TimeCache {

    public static Map<String, Long> sStartTime = new HashMap<>();
    public static Map<String, Long> sEndTime = new HashMap<>();

    public static void setStartTime(String methodName, long time) {
        sStartTime.put(methodName, time);
    }

    public static void setEndTime(String methodName, long time) {
        sEndTime.put(methodName, time);
    }

    public static String getCostTime(String methodName) {
        long start = sStartTime.get(methodName);
        long end = sEndTime.get(methodName);
        return "method: " + methodName + " main " + Long.valueOf(end - start) + " ns";
    }

}

然后便是插入时间统计代码了，我在之前的一篇文章就有介绍过 手摸手增加字节码往方法体内插代码 ，我们可以借助一个intelliJ plugin --
ASM Bytecode Outline来方便我们写ASM代码，先把原java代码写好：

System.out.println("========start=========");
TimeUtil.setsStartTime("newFunc", System.nanoTime());
        
TimeUtil.setEndTime("newFunc", System.nanoTime());
System.out.println(TimeCache.getCostTime("newFunc"));
System.out.println("========end=========");

然后利用插件，生成对应ASM代码，删除掉无用信息后，可得到：

mv.visitFieldInsn(GETSTATIC, "java/lang/System", "out", "Ljava/io/PrintStream;");
mv.visitLdcInsn("========start=========");
mv.visitMethodInsn(INVOKEVIRTUAL, "java/io/PrintStream", "println", "(Ljava/lang/String;)V", false);

mv.visitLdcInsn(name);
mv.visitMethodInsn(INVOKESTATIC, "java/lang/System", "nanoTime", "()J", false);
mv.visitMethodInsn(INVOKESTATIC, "main/java/TimeCache", "setStartTime", "(Ljava/lang/String;J)V", false);

...

mv.visitLdcInsn(name);
mv.visitMethodInsn(INVOKESTATIC, "java/lang/System", "nanoTime", "()J", false);
mv.visitMethodInsn(INVOKESTATIC, "main/java/TimeCache", "setEndTime", "(Ljava/lang/String;J)V", false);

mv.visitFieldInsn(GETSTATIC, "java/lang/System", "out", "Ljava/io/PrintStream;");
mv.visitLdcInsn(name);
mv.visitMethodInsn(INVOKESTATIC, "main/java/TimeCache", "getCostTime", "(Ljava/lang/String;)Ljava/lang/String;", false);
mv.visitMethodInsn(INVOKEVIRTUAL, "java/io/PrintStream", "println", "(Ljava/lang/String;)V", false);

mv.visitFieldInsn(GETSTATIC, "java/lang/System", "out", "Ljava/io/PrintStream;");
mv.visitLdcInsn("========end=========");
mv.visitMethodInsn(INVOKEVIRTUAL, "java/io/PrintStream", "println", "(Ljava/lang/String;)V", false);

那么我们将这部分ASM代码填充到刚刚遗留下来的CostClassVisitor.java里便可。

这样一来，我们的ASM工作已经结束，接下来就是来让插入的方法运行起来。

反射实例化

先来一种简单的方案，就是将我们插入代码后二进制流手动生成.class文件并利用反射实例化它。

首先来看看插入前的代码：

public class Bazhang {

  public void newFunc1(String str) {
    System.out.println(str);
    for (int i = 0; i < 100; i++) {
      if (i % 10 == 0) {
        System.out.println(i);
      }
      if (i == 50) {
        return;
      }
    }
  }

  @Cost
  public void newFunc2(String str) {
    System.out.println(str);
    for (int i = 0; i < 100; i++) {
      if (i % 8 == 0) {
        System.out.println(i);
      }
      if (i > 50) {
        return;
      }
    }
  }

}

我给newFunc2方法增加了@Cost注解，但没给newFunc1方法增加，然后开始用ASM提供的类生成插入代码后的二进制流：

ClassReader cr = new ClassReader(Bazhang.class.getName());
ClassWriter cw = new ClassWriter(cr, ClassWriter.COMPUTE_MAXS);
ClassVisitor cv = new CostClassVisitor(cw);

cr.accept(cv, EXPAND_FRAMES);

// 获取生成的class文件对应的二进制流
byte[] code = cw.toByteArray();

//将二进制流写到out/下
FileOutputStream fos = new FileOutputStream(System.getProperty("user.dir")
            + "/javademo/build/classes/main/wangyuwei/demo/Bazhang.class");
fos.write(code);
fos.close();

Demo loader = new Demo();
Class hw = loader.defineClass("wangyuwei.demo.Bazhang", code, 0, code.length);
Object o = hw.newInstance();
Method method1 = o.getClass().getMethod("newFunc1", String.class);
method1.invoke(o, "巴掌菜比");
Method method2 = o.getClass().getMethod("newFunc2", String.class);
method2.invoke(o, "巴掌菜比22");

然后run一下，可以得到：

巴掌菜比
0
10
20
30
40
50
========start=========
巴掌菜比22
0
8
16
24
32
40
48
method: newFunc2 main 1647919 ns
========end=========

只对newFunc2做了方法耗时统计。

使用Instrumentation构建代理

Instrumentation是Java5提供的新特性，关于详细介绍，可以查看这篇文章：Java 5 特性 Instrumentation 实践，简单点说就是我们得在JVM执行main函数前动点手脚，自己实现一个代理，在得到虚拟机载入的正常的类的字节码后通过ASM提供的类生成一个插入代码后的字节流再丢给虚拟机，自定义的代理得实现ClassFileTransformer，并且提供premain()方法，写有premain方法的类得在MANIFEST.MF中显示调用，首先来看看我们自定义的代理类：

public class CostClassFileTransformer implements ClassFileTransformer {

    public static void premain(String args, Instrumentation inst) {
        inst.addTransformer(new CostClassFileTransformer());
    }

    @Override
    public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined, ProtectionDomain protectionDomain, byte[] classfileBuffer) throws IllegalClassFormatException {
        ClassReader reader = new ClassReader(classfileBuffer);
        ClassWriter writer = new ClassWriter(reader, ClassWriter.COMPUTE_MAXS);
        reader.accept(new CostClassVisitor(writer), 8);
        return writer.toByteArray();
    }
}

再看看MANIFEST.MF：

Manifest-Version: 1.0
Premain-Class: wangyuwei.costtime.CostClassFileTransformer

这样写好代理类之后，我们便可以生成一个代理jar，之后为我们运行代码使用，进入module javademo，生成jar可直接使用命令：

jar -cvfm lib/cost-time.jar src/main/META-INF/MANIFEST.MF src/main/java/wangyuwei/costtime/CostClassFileTransformer.class

得到代理jar后，再使用命令行java -javaagent:lib的绝对地址/cost-time.jar Demo2.java运行即可，如果在使用命令行运行时带来了问题，可以直接通过对IntelliJ IDE进行修改：

Windows, Linux, some Macs:

ALT+SHIFT+F10->Right->E->Enter->Tab->enter your command line parameters->Enter.

Mac with "OS X 10.5" key schema:

CTRL+ALT+R->Right->E->Enter->Tab->enter your command line parameters->Enter.

在VM options一栏填入-javaagent:lib/cost-time.jar即可。

以上便是运行在JVM上的操作，然而我们最终的目标是为Android平台所用。

gradle plugin 自定义Transform Api

Transform API允许第三方插件在class文件转为为dex文件前操作编译好的class文件，那么这就是我们的入口，拿到正常的class后再经过ASM插入字节码后得到新的class，再被dx转成dex。

首先自定义个plugin--CostTimePlugin.groovy：

public class CostTimePlugin extends Transform implements Plugin<Project> {
  @Override public void apply(Project project) {

    def android = project.extensions.getByType(AppExtension)
    android.registerTransform(this)
  }

  @Override
  String getName() {
    return "bazhang"
  }

  @Override
  Set<QualifiedContent.ContentType> getInputTypes() {
    return TransformManager.CONTENT_CLASS
  }

  @Override
  Set<QualifiedContent.Scope> getScopes() {
    return TransformManager.SCOPE_FULL_PROJECT
  }

  @Override
  boolean isIncremental() {
    return false
  }

  @Override
  void transform(Context context, Collection<TransformInput> inputs,
      Collection<TransformInput> referencedInputs, TransformOutputProvider outputProvider,
      boolean isIncremental) throws IOException, TransformException, InterruptedException {
    println '//===============asm visit start===============//'

    def startTime = System.currentTimeMillis()

    inputs.each { TransformInput input ->

      input.directoryInputs.each { DirectoryInput directoryInput ->

        //坐等遍历class并被ASM操作

        def dest = outputProvider.getContentLocation(directoryInput.name,
            directoryInput.contentTypes, directoryInput.scopes,
            Format.DIRECTORY)


        FileUtils.copyDirectory(directoryInput.file, dest)
      }

      input.jarInputs.each { JarInput jarInput ->
        def jarName = jarInput.name
        def md5Name = DigestUtils.md5Hex(jarInput.file.getAbsolutePath())
        if (jarName.endsWith(".jar")) {
          jarName = jarName.substring(0, jarName.length() - 4)
        }

        def dest = outputProvider.getContentLocation(jarName + md5Name,
            jarInput.contentTypes, jarInput.scopes, Format.JAR)

        FileUtils.copyFile(jarInput.file, dest)
      }
    }

    def cost = (System.currentTimeMillis() - startTime) / 1000

    println "plugin cost $cost secs"
    println '//===============asm visit end===============//'
  }
}

我们预留了一行注释，去遍历build/intermediates/classes/release/下面生成的所有class，当然R.class、BuildConfig.class这些我们就可以直接跳过，ASM过滤一遍插入新代码之后再去覆盖原class，代码如下：

if (directoryInput.file.isDirectory()) {
    directoryInput.file.eachFileRecurse { File file ->
        def name = file.name
        if (name.endsWith(".class") && !name.startsWith("R\$") &&
            !"R.class".equals(name) && !"BuildConfig.class".equals(name)) {

            println name + ' is changing...'

            ClassReader cr = new ClassReader(file.bytes);
            ClassWriter cw = new ClassWriter(cr, ClassWriter.COMPUTE_MAXS);
            ClassVisitor cv = new CostClassVisitor(cw);

            cr.accept(cv, EXPAND_FRAMES);

            byte[] code = cw.toByteArray();

            FileOutputStream fos = new FileOutputStream(
                file.parentFile.absolutePath + File.separator + name);
            fos.write(code);
            fos.close();
        }
    }
}

这样一来，我们可以看看新生成的class是不是有被插入代码。

这是源代码MainActivity.java：

public class MainActivity extends AppCompatActivity {

  @Override
  protected void onCreate(Bundle savedInstanceState) {
    super.onCreate(savedInstanceState);
    setContentView(R.layout.activity_main);
  }

  @Cost
  public void show() {
    for (int i = 0; i < 100; i++) {

    }
  }
}

这是build/intermediates/classes/release/里的MainActivity.class：

public class MainActivity extends AppCompatActivity {
  public MainActivity() {
  }

  protected void onCreate(Bundle savedInstanceState) {
    super.onCreate(savedInstanceState);
    this.setContentView(2130968603);
  }

  @Cost
  public void show() {
    System.out.println("========start=========");
    TimeCache.setStartTime("show", System.nanoTime());

    for(int i = 0; i < 100; ++i) {
      ;
    }

    TimeCache.setEndTime("show", System.nanoTime());
    System.out.println(TimeCache.getCostTime("show"));
    System.out.println("========end=========");
  }
}

而且我们可以看下build过程：

:app:transformClassesWithBazhangForRelease
//===============asm visit start===============//
Demo.class is changing...
MainActivity.class is changing...
plugin cost 0.148 secs
//===============asm visit end===============//
:app:processReleaseJavaRes 
:app:transformResourcesWithMergeJavaResForRelease
:app:transformClassesAndResourcesWithProguardForRelease

我们的class操作是在混淆前的，那么此次AOP也完全不影响正常的混淆，可看混淆后的MainActivity.java：


public class MainActivity extends f {
    protected void onCreate(Bundle bundle) {
        super.onCreate(bundle);
        setContentView((int) R.layout.activity_main);
    }

    @a
    public void p() {
        System.out.println("========start=========");
        b.a("show", System.nanoTime());
        for (int i = 0; i < 100; i++) {
        }
        b.b("show", System.nanoTime());
        System.out.println(b.a("show"));
        System.out.println("========end=========");
    }
}

尾语

我们采取的方案其实大有可为，计算方法耗时只是冰山一角，包括无数据埋点、性能的监控都是可以继续拓展的。以上方案难免有些漏洞，欢迎指出，有兴趣的朋友可以一起探讨。

最后编辑于 ：
©著作权归作者所有,转载或内容合作请联系作者
  • 人面猴
    序言：七十年代末，一起剥皮案震惊了整个滨河市，随后出现的几起案子，更是在滨河造成了极大的恐慌，老刑警刘岩，带你破解...
    沈念sama阅读 203,324评论 5赞 476
  • 死咒
    序言：滨河连续发生了三起死亡事件，死亡现场离奇诡异，居然都是意外死亡，警方通过查阅死者的电脑和手机，发现死者居然都...
    沈念sama阅读 85,303评论 2赞 381
  • 救了他两次的神仙让他今天三更去死
    文/潘晓璐 我一进店门，熙熙楼的掌柜王于贵愁眉苦脸地迎上来，“玉大人，你说我怎么就摊上这事。” “怎么了？”我有些...
    开封第一讲书人阅读 150,192评论 0赞 337
  • 道士缉凶录：失踪的卖姜人
    文/不坏的土叔 我叫张陵，是天一观的道长。 经常有香客问我，道长，这世上最难降的妖魔是什么？ 我笑而不...
    开封第一讲书人阅读 54,555评论 1赞 273
  • 港岛之恋（遗憾婚礼）
    正文 为了忘掉前任，我火速办了婚礼，结果婚礼上，老公的妹妹穿的比我还像新娘。我一直安慰自己，他们只是感情好，可当我...
    茶点故事阅读 63,569评论 5赞 365
  • 恶毒庶女顶嫁案：这布局不是一般人想出来的
    文/花漫 我一把揭开白布。 她就那样静静地躺着，像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上，一...
    开封第一讲书人阅读 48,566评论 1赞 281
  • 城市分裂传说
    那天，我揣着相机与录音，去河边找鬼。 笑死，一个胖子当着我的面吹牛，可吹牛的内容都是我干的。 我是一名探鬼主播，决...
    沈念sama阅读 37,927评论 3赞 395
  • 双鸳鸯连环套：你想象不到人心有多黑
    文/苍兰香墨 我猛地睁开眼，长吁一口气：“原来是场噩梦啊……” “哼！你这毒妇竟也来了？” 一声冷哼从身侧响起，我...
    开封第一讲书人阅读 36,583评论 0赞 257
  • 万荣杀人案实录
    序言：老挝万荣一对情侣失踪，失踪者是张志新（化名）和其女友刘颖，没想到半个月后，有当地人在树林里发现了一具尸体，经...
    沈念sama阅读 40,827评论 1赞 297
  • 护林员之死
    正文 独居荒郊野岭守林人离奇死亡，尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,590评论 2赞 320
  • 白月光启示录
    正文 我和宋清朗相恋三年，在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,669评论 1赞 329
  • 活死人
    序言：一个原本活蹦乱跳的男人离奇死亡，死状恐怖，灵堂内的尸体忽然破棺而出，到底是诈尸还是另有隐情，我是刑警宁泽，带...
    沈念sama阅读 33,365评论 4赞 318
  • 日本核电站爆炸内幕
    正文 年R本政府宣布，位于F岛的核电站，受9级特大地震影响，放射性物质发生泄漏。R本人自食恶果不足惜，却给世界环境...
    茶点故事阅读 38,941评论 3赞 307
  • 男人毒药：我在死后第九天来索命
    文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹，春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,928评论 0赞 19
  • 一桩弑父案，背后竟有这般阴谋
    文/苍兰香墨 我抬头看了看天上的太阳。三九已至，却和暖如春，着一层夹袄步出监牢的瞬间，已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,159评论 1赞 259
  • 情欲美人皮
    我被黑心中介骗来泰国打工， 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留，地道东北人。 一个月前我还...
    沈念sama阅读 42,880评论 2赞 349
  • 代替公主和亲
    正文 我出身青楼，却偏偏与公主长得像，于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子，可洞房花烛夜当晚...
    茶点故事阅读 42,399评论 2赞 342

推荐阅读更多精彩内容

  • Android - 收藏集
    Android 自定义View的各种姿势1 Activity的显示之ViewRootImpl详解 Activity...
    passiontim阅读 171,391评论 25赞 707
  • Spring Cloud
    Spring Cloud为开发人员提供了快速构建分布式系统中一些常见模式的工具（例如配置管理，服务发现，断路器，智...
    卡卡罗2017阅读 134,580评论 18赞 139
  • Spring boot参考指南
    Spring Boot 参考指南 介绍 转载自:https://www.gitbook.com/book/qbgb...
    毛宇鹏阅读 46,724评论 6赞 342
  • 修炼成圣
    一个人经历的越多， 他的抱怨就会越少。 越是优秀的人越努力； 越是富有的人越勤奋； 越是智慧的人越谦卑。 这是因为...
    李星辰1314阅读 250评论 0赞 0
  • 每天想很多的事
    每天想很多的事， 我可以来数一数。 太阳出来的时候，我想， 阳光真是温暖。 猫一直叫的时候，我想， 它们...
    程子秋阅读 194评论 0赞 1