最通俗易懂的字节码插桩实战(Gradle + ASM)—— 优雅的打印方法执行时间

前言

做项目优化时,我们通常会先打印出方法的执行时间,再根据方法的耗时情况对其进行优化。代码如下:

public static void main(String[] args) {
        long startTime = System.currentTimeMillis(); 
        //...
        long endTime = System.currentTimeMillis(); 
        System.out.println("程序运行时间: " + (endTime - startTime) + "ms");
    }

如果是一两个方法我们手动插入代码没有问题,但是整个项目的方法何其多,都要我们手动去插入的话,估计能把C、V两键扣废掉。那么有没有一种优雅的方式实现耗时打印呢?当然有的,这就是今天要介绍的主角 ASM (字节码插桩)。

有同学到这里可能就会问,我不会写ASM代码该怎么办呢?

悄悄的跟你说,其实我也不会写ASM代码。

那这会影响到我们的开发吗?

当然不会了,如果有影响就不会有这篇文章了。

ASM Bytecode Viewer

ASM Bytecode Viewer是一款能 查看字节码生成ASM代码 的插件,是帮助我们学习ASM的利器,剩下就是对ASM的熟悉和使用可以说是so easy。

  • 在Android Studio中搜索 ASM Bytecode Viewer Support Kotlin 找到并安装。
  • 代码右键 ASM Bytecode Viewer 便能自动生成ASM插桩代码。

ASMASM Bytecode Viewer 我在之前的文章 最通俗易懂的字节码插桩实战(Gradle + ASM)—— 自动埋点 已经介绍过了,有不了解的同学可以翻看一下。具体使用方法我会在后面的编码阶段详细介绍。

实战

至此我们已经做了大量的准备工作,现在就正式进入实战环节。
首先创建一个module作为插件开发,再删除掉多余的文件,然后创建groovy目录供代码编写……
PS:由于gradle插件开发并不是我们今天的任务,这里就不过多的展开说明了,具体代码可在 github 上查看,module目录结构如下:

1、StatisticPlugin

我们本次编写的插件,在apply 方法的注册 MethodTimerTransform,并读取 build.gradle 里面配置信息。

class StatisticPlugin implements Plugin<Project> {

    public static List<MethodTimerEntity> METHOD_TIMER_LIST

    @Override
    void apply(Project project) {
        def android = project.extensions.findByType(AppExtension)
        // 注册Transform
        android.registerTransform(new MethodTimerTransform())
        // 获取gradle里面配置的埋点信息
        def statisticExtension = project.extensions.create('statistic', StatisticExtension)
        project.afterEvaluate {
            // 获取方法计时信息,将其保存在METHOD_TIMER_LIST方便调用
            METHOD_TIMER_LIST = new ArrayList<>()
            def methodTimer = statisticExtension.getMethodTimer()
            if (methodTimer != null) {
                methodTimer.each { Map<String, Object> map ->
                    MethodTimerEntity entity = new MethodTimerEntity()
                    if (map.containsKey("time")) {
                        entity.time = map.get("time")
                    }
                    if (map.containsKey("owner")) {
                        entity.owner = map.get("owner")
                    }
                    METHOD_TIMER_LIST.add(entity)
                }
            }
        }
    }
}
2、MethodTimerTransform

通过transform 方法的 Collection<TransformInput> inputs 对 .class文件遍历拿到所有方法。

class MethodTimerTransform extends Transform {

    ...省略中间非关键代码,详细请到github中查看...

    /**
     *
     * @param context
     * @param inputs 有两种类型,一种是目录,一种是 jar 包,要分开遍历
     * @param outputProvider 输出路径
     */
    @Override
    void transform(
            @NonNull Context context,
            @NonNull Collection<TransformInput> inputs,
            @NonNull Collection<TransformInput> referencedInputs,
            @Nullable TransformOutputProvider outputProvider,
            boolean isIncremental
    ) throws IOException, TransformException, InterruptedException {
        if (!incremental) {
            //不是增量更新删除所有的outputProvider
            outputProvider.deleteAll()
        }
        inputs.each { TransformInput input ->
            //遍历目录
            input.directoryInputs.each { DirectoryInput directoryInput ->
                handleDirectoryInput(directoryInput, outputProvider)
            }
            // 遍历jar 第三方引入的 class
            input.jarInputs.each { JarInput jarInput ->
                handleJarInput(jarInput, outputProvider)
            }
        }
    }

}
3、MethodTimerClassVisitor

通过visitMethod拿到方法进行修改。

class MethodTimerClassVisitor extends ClassVisitor {

    ...省略中间非关键代码,详细请到github中查看...

    /**
     * 扫描类的方法进行调用
     * @param access 修饰符
     * @param name 方法名字
     * @param descriptor 方法签名
     * @param signature 泛型信息
     * @param exceptions 抛出的异常
     * @return
     */
    @Override
    MethodVisitor visitMethod(int methodAccess, String methodName, String methodDescriptor, String signature, String[] exceptions) {
        MethodVisitor methodVisitor = super.visitMethod(methodAccess, methodName, methodDescriptor, signature, exceptions)
        if ((methodAccess & Opcodes.ACC_INTERFACE) == 0 && "<init>" != methodName && "<clinit>" != methodName) {
            methodVisitor = new MethodTimerAdviceAdapter(api, methodVisitor, methodAccess, methodName, methodDescriptor)
        }
        return methodVisitor
    }

}
4、MethodTimerAdviceAdapter

这里就是我们插入打印方法耗时的地方了,可以看到代码没有很多。

  • onMethodEnter在方法进入时调用,我们先在这里插入一个时间戳,标记方法开始的时间。
  • onMethodExit在方法退出前调用,这里我们也插入一个时间戳,标记方法结束的时间。最后把两个时间戳相减得到方法耗时时间并打印。

听完解释后是不是觉得非常简单呢。

大家最关心的编(sheng)写(cheng)ASM代码,今天它来了。
  1. 首先我们创建一个Test类,先用java代码来实现我们的需求,代码如下:
public class Test {

    public static void main(String[] args) {
        long startTime = System.currentTimeMillis();
        String str = "--- I'm the code line ---";
        long endTime = System.currentTimeMillis();
        long time = endTime - startTime;
        if(time > 500){
            System.out.println("程序运行时间: " + time + "ms");
        }
    }

}

细心的同学会发现代码中有一段分割线字符串 String str = "--- I'm the code line ---";
前面说过方法进入时和方法退出前分别是 onMethodEnteronMethodExit,因此我们通过分割线字符串来判断代码插入的时机。
分割线字符之前的代码在 onMethodEnter 插入,分割线字符之后的代码在onMethodExit插入。

  1. 代码右键 ASM Bytecode Viewer 自动生成ASM插桩代码,生成代码如下:
        {
            methodVisitor = classWriter.visitMethod(ACC_PUBLIC | ACC_STATIC, "main", "([Ljava/lang/String;)V", null, null);
            methodVisitor.visitParameter("args", 0);
            methodVisitor.visitCode();
            methodVisitor.visitMethodInsn(INVOKESTATIC, "java/lang/System", "currentTimeMillis", "()J", false);
            methodVisitor.visitVarInsn(LSTORE, 1);
            methodVisitor.visitLdcInsn("--- I'm the code line ---");
            methodVisitor.visitVarInsn(ASTORE, 3);
            methodVisitor.visitMethodInsn(INVOKESTATIC, "java/lang/System", "currentTimeMillis", "()J", false);
            methodVisitor.visitVarInsn(LSTORE, 4);
            methodVisitor.visitVarInsn(LLOAD, 4);
            methodVisitor.visitVarInsn(LLOAD, 1);
            methodVisitor.visitInsn(LSUB);
            methodVisitor.visitVarInsn(LSTORE, 6);
            methodVisitor.visitVarInsn(LLOAD, 6);
            methodVisitor.visitLdcInsn(new Long(500L));
            methodVisitor.visitInsn(LCMP);
            Label label0 = new Label();
            methodVisitor.visitJumpInsn(IFLE, label0);
            methodVisitor.visitFieldInsn(GETSTATIC, "java/lang/System", "out", "Ljava/io/PrintStream;");
            methodVisitor.visitTypeInsn(NEW, "java/lang/StringBuilder");
            methodVisitor.visitInsn(DUP);
            methodVisitor.visitMethodInsn(INVOKESPECIAL, "java/lang/StringBuilder", "<init>", "()V", false);
            methodVisitor.visitLdcInsn("\u7a0b\u5e8f\u8fd0\u884c\u65f6\u95f4\uff1a ");
            methodVisitor.visitMethodInsn(INVOKEVIRTUAL, "java/lang/StringBuilder", "append", "(Ljava/lang/String;)Ljava/lang/StringBuilder;", false);
            methodVisitor.visitVarInsn(LLOAD, 6);
            methodVisitor.visitMethodInsn(INVOKEVIRTUAL, "java/lang/StringBuilder", "append", "(J)Ljava/lang/StringBuilder;", false);
            methodVisitor.visitLdcInsn("ms");
            methodVisitor.visitMethodInsn(INVOKEVIRTUAL, "java/lang/StringBuilder", "append", "(Ljava/lang/String;)Ljava/lang/StringBuilder;", false);
            methodVisitor.visitMethodInsn(INVOKEVIRTUAL, "java/lang/StringBuilder", "toString", "()Ljava/lang/String;", false);
            methodVisitor.visitMethodInsn(INVOKEVIRTUAL, "java/io/PrintStream", "println", "(Ljava/lang/String;)V", false);
            methodVisitor.visitLabel(label0);
            methodVisitor.visitInsn(RETURN);
            methodVisitor.visitMaxs(4, 8);
            methodVisitor.visitEnd();
        }

我们把 methodVisitor.visitCode(); 之后 methodVisitor.visitLdcInsn("--- I'm the code line ---"); 之前的代码插入到 onMethodEnter 。把 methodVisitor.visitLdcInsn("--- I'm the code line ---"); 之后 methodVisitor.visitInsn(RETURN); 之前的代码插入到 onMethodExit

最终的 MethodTimerAdviceAdapter 代码如下:

class MethodTimerAdviceAdapter extends AdviceAdapter {

    int slotIndex

    ...省略中间非关键代码,详细请到github中查看...

    @Override
    protected void onMethodEnter() {
        super.onMethodEnter()
        for (MethodTimerEntity entity : StatisticPlugin.METHOD_TIMER_LIST) {
            if (methodOwner.contains(entity.getOwner())) {
                slotIndex = newLocal(Type.LONG_TYPE)
                mv.visitMethodInsn(INVOKESTATIC, "java/lang/System", "currentTimeMillis", "()J", false)
                mv.visitVarInsn(LSTORE, slotIndex)
            }
        }
    }

    @Override
    void onMethodExit(int opcode) {
        for (MethodTimerEntity entity : StatisticPlugin.METHOD_TIMER_LIST) {
            if (methodOwner.contains(entity.getOwner())) {
                mv.visitMethodInsn(INVOKESTATIC, "java/lang/System", "currentTimeMillis", "()J", false)
                mv.visitVarInsn(LLOAD, slotIndex)
                mv.visitInsn(LSUB)
                mv.visitVarInsn(LSTORE, slotIndex)
                mv.visitVarInsn(LLOAD, slotIndex)
                mv.visitLdcInsn(new Long(entity.getTime()))
                mv.visitInsn(LCMP)
                Label label0 = new Label()
                mv.visitJumpInsn(IFLE, label0)
                mv.visitFieldInsn(GETSTATIC, "java/lang/System", "out", "Ljava/io/PrintStream;")
                mv.visitTypeInsn(NEW, "java/lang/StringBuilder")
                mv.visitInsn(DUP)
                mv.visitMethodInsn(INVOKESPECIAL, "java/lang/StringBuilder", "<init>", "()V", false)
                mv.visitLdcInsn(methodOwner + "/" + methodName + " --> execution time : (")
                mv.visitMethodInsn(INVOKEVIRTUAL, "java/lang/StringBuilder", "append", "(Ljava/lang/String;)Ljava/lang/StringBuilder;", false)
                mv.visitVarInsn(LLOAD, slotIndex)
                mv.visitMethodInsn(INVOKEVIRTUAL, "java/lang/StringBuilder", "append", "(J)Ljava/lang/StringBuilder;", false)
                mv.visitLdcInsn("ms)")
                mv.visitMethodInsn(INVOKEVIRTUAL, "java/lang/StringBuilder", "append", "(Ljava/lang/String;)Ljava/lang/StringBuilder;", false)
                mv.visitMethodInsn(INVOKEVIRTUAL, "java/lang/StringBuilder", "toString", "()Ljava/lang/String;", false)
                mv.visitMethodInsn(INVOKEVIRTUAL, "java/io/PrintStream", "println", "(Ljava/lang/String;)V", false)
                mv.visitLabel(label0)
            }
        }
        super.onMethodExit(opcode)
    }

}
---这里画个重点---

局部变量表(Local Variable Table) 是一组变量值存储空间,用于存放方法参数和方法内定义的局部变量。具体的顺序是 this-方法接收的参数-方法内定义的局部变量 。而我们通过 ASM Bytecode Viewer 生成的ASM代码是1,2,3按顺序写死的,所以我们通过 newLocal(type) 来重新获取压入的位置 slotIndex 把参数压入到局部变量表中。

5、 如何使用?
5.1、 先打包插件到本地仓库进行引用
5.2、 在项目的根build.gradle加入插件的依赖
    repositories {
        google()
        mavenCentral()
        jcenter()
        maven{
            url uri('repos')
        }
    }
    dependencies {
        classpath "com.android.tools.build:gradle:$gradle_version"
        classpath "org.jetbrains.kotlin:kotlin-gradle-plugin:$kotlin_version"
        classpath 'com.meituan.android.walle:plugin:1.1.7'
        // 使用自定义插件
        classpath 'com.example.plugin:statistic:1.0.0'
        // NOTE: Do not place your application dependencies here; they belong
        // in the individual module build.gradle files
    }
5.3、 在app的build.gradle中使用并配置参数
plugins {
    id 'com.android.application'
    id 'statistic'
}

statistic {
        methodTimer = [
            [
                    // 打印大于time的方法
                    'time'  : 500L,
                    // 需要打印方法的范围
                    'owner': 'com/example/fragment',
            ],
            [
                    'time'  : 5000L,
                    'owner': 'com/google',
            ]
    ]
}
6、 运行项目查看输出日志
2021-07-20 11:31:51.915 12028-12060/com.example.fragment.project.debug I/System.out: com/example/fragment/library/base/http/SimpleHttp$get$2/invokeSuspend --> execution time : (2066ms)
2021-07-20 11:31:52.565 12028-12028/com.example.fragment.project.debug I/System.out: com/example/fragment/library/common/utils/WanHelper/setTreeList --> execution time : (1184ms)
2021-07-20 11:31:52.565 12028-12028/com.example.fragment.project.debug I/System.out: com/example/fragment/project/model/MainViewModel$getTree$1/invokeSuspend --> execution time : (1184ms)
2021-07-20 11:31:53.768 12028-12028/com.example.fragment.project.debug I/System.out: com/example/fragment/library/common/utils/WanHelper/setTreeList --> execution time : (1186ms)
2021-07-20 11:31:53.768 12028-12028/com.example.fragment.project.debug I/System.out: com/example/fragment/module/system/model/SystemViewModel$getTree$1/invokeSuspend --> execution time : (1186ms)

Thanks

以上就是本篇文章的全部内容,如有问题欢迎指出,我们一起进步。
如果喜欢的话希望点个赞吧,您的鼓励是我前进的动力。
谢谢~~

项目地址

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 212,686评论 6 492
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 90,668评论 3 385
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 158,160评论 0 348
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 56,736评论 1 284
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 65,847评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,043评论 1 291
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,129评论 3 410
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 37,872评论 0 268
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,318评论 1 303
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,645评论 2 327
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 38,777评论 1 341
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,470评论 4 333
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,126评论 3 317
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 30,861评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,095评论 1 267
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,589评论 2 362
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,687评论 2 351

推荐阅读更多精彩内容