JVM Profiler 方法耗时采集

开篇

 JVM Profile的方法采集通过修改字节码在原来方法体的前置和后置增加采集耗时的代码。核心是基于基于java自带的instrument包和javassist包来实现的。

整个核心逻辑如下

  • 得到用户传入需要拦截的方法列表。
  • 在方法前后织入前置和后置耗时统计代码。
  • 内部保存耗时然后上报耗时。


源码分析

  • durationProfilingFilter 保存需要采集耗时的方法列表。
  • argumentFilterProfilingFilter 保存需要采集方法参数的方法列表。
public class JavaAgentFileTransformer implements ClassFileTransformer {
    private static final AgentLogger logger = AgentLogger.getLogger(JavaAgentFileTransformer.class.getName());

    private ClassAndMethodFilter durationProfilingFilter;
    private ClassMethodArgumentFilter argumentFilterProfilingFilter;

    /**
     *
     * @param durationProfiling 是采集的类和接口封装的对象
     * @param argumentProfiling 是
     */
    public JavaAgentFileTransformer(List<ClassAndMethod> durationProfiling, List<ClassMethodArgument> argumentProfiling) {
        this.durationProfilingFilter = new ClassAndMethodFilter(durationProfiling);
        this.argumentFilterProfilingFilter = new ClassMethodArgumentFilter(argumentProfiling);
    }
}

转码过程

  • 获取类的字节码并解析类的method。
  • 判断method是否在采集列表当中,如果不在采集列表就直接返回。
  • 针对所有需要被采集耗时的方法通过transformMethod进行字节码修改。
    public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined, ProtectionDomain protectionDomain, byte[] classfileBuffer) throws IllegalClassFormatException {
        try {
            // 用于对原有的类进行转换并返回新的字节码
            if (className == null || className.isEmpty()) {
                logger.debug("Hit null or empty class name");
                return null;
            }
            return transformImpl(loader, className, classfileBuffer);
        } catch (Throwable ex) {
            logger.warn("Failed to transform class " + className, ex);
            return classfileBuffer;
        }
    }

    private byte[] transformImpl(ClassLoader loader, String className, byte[] classfileBuffer) {
        // 判断监控列表是否为空
        if (durationProfilingFilter.isEmpty()
                && argumentFilterProfilingFilter.isEmpty()) {
            return null;
        }

        // 转换类名替换"/"为"."
        String normalizedClassName = className.replaceAll("/", ".");
        logger.debug("Checking class for transform: " + normalizedClassName);

        // 判断是否在监控列表当中
        if (!durationProfilingFilter.matchClass(normalizedClassName)
                && !argumentFilterProfilingFilter.matchClass(normalizedClassName)) {
            return null;
        }

        byte[] byteCode;

        logger.info("Transforming class: " + normalizedClassName);

        try {
            // ClassPool首先负责加载该类然后判断该类的方法是否在拦截列表当中
            ClassPool classPool = new ClassPool();
            classPool.appendClassPath(new LoaderClassPath(loader));
            final CtClass ctClass;
            try (ByteArrayInputStream byteArrayInputStream = new ByteArrayInputStream(classfileBuffer)) {
                ctClass = classPool.makeClass(byteArrayInputStream);
            }
            
            CtMethod[] ctMethods = ctClass.getDeclaredMethods();
            for (CtMethod ctMethod : ctMethods) {
                boolean enableDurationProfiling = durationProfilingFilter.matchMethod(ctClass.getName(), ctMethod.getName());
                List<Integer> enableArgumentProfiler = argumentFilterProfilingFilter.matchMethod(ctClass.getName(), ctMethod.getName());

                // 修改方法的字节码
                transformMethod(normalizedClassName, ctMethod, enableDurationProfiling, enableArgumentProfiler);
            }

            // 返回类的二进制编码
            byteCode = ctClass.toBytecode();
            // ClassPool中删除该类
            ctClass.detach();

        } catch (Throwable ex) {
            ex.printStackTrace();
            logger.warn("Failed to transform class: " + normalizedClassName, ex);
            byteCode = null;
        }

        return byteCode;
    }

方法增加前后置采集代码

  • 通过method.insertBefore()在原有的方法体前置添加耗时采集代码。
  • 通过method.insertAfter()在原有的方法体后置添加耗时采集代码
    // 对类进行前后拦截
    private void transformMethod(String normalizedClassName, CtMethod method, boolean enableDurationProfiling, List<Integer> argumentsForProfile) {
        if (method.isEmpty()) {
            logger.info("Ignored empty class method: " + method.getLongName());
            return;
        }

        if (!enableDurationProfiling && argumentsForProfile.isEmpty()) {
            return;
        }

        try {
            // 在方法中增加局部计时变量 startMillis_java_agent_instrument 和 durationMillis_java_agent_instrument
            if (enableDurationProfiling) {
                method.addLocalVariable("startMillis_java_agent_instrument", CtClass.longType);
                method.addLocalVariable("durationMillis_java_agent_instrument", CtClass.longType);
            }

            // 添加前置拦截代码
            StringBuilder sb = new StringBuilder();
            // 代码块的开始标志 "{"
            sb.append("{");

            // 添加开始采集程序执行开始时间的代码
            if (enableDurationProfiling) {
                sb.append("startMillis_java_agent_instrument = System.currentTimeMillis();");
            }

            // 如果该方法的某个参数需要被采集,添加采集代码
            for (Integer argument : argumentsForProfile) {
                if (argument >= 1) {
                    // 在javassist当中$1表示执行中第一个参数的值,这里根据传进来的下标argument来标识监控那个具体参数
                    // collectMethodArgument负责对接口参数的值进行监控
                    sb.append(String.format("try{com.uber.profiling.transformers.MethodProfilerStaticProxy.collectMethodArgument(\"%s\", \"%s\", %s, String.valueOf($%s));}catch(Throwable ex){ex.printStackTrace();}",
                            normalizedClassName,
                            method.getName(),
                            argument,
                            argument));
                } else {
                    // 如果等于0那么采用其他方法进行采集
                    sb.append(String.format("try{com.uber.profiling.transformers.MethodProfilerStaticProxy.collectMethodArgument(\"%s\", \"%s\", %s, \"\");}catch(Throwable ex){ex.printStackTrace();}",
                            normalizedClassName,
                            method.getName(),
                            argument,
                            argument));
                }
            }
            // 添加代码块结尾
            sb.append("}");

            // 在原有方法体之前插入前置代码块
            method.insertBefore(sb.toString());

            if (enableDurationProfiling) {
                // 在原有方法体之后插入后置代码块
                // collectMethodDuration负责采集接口耗时
                method.insertAfter("{" +
                        "durationMillis_java_agent_instrument = System.currentTimeMillis() - startMillis_java_agent_instrument;" +
                        String.format("try{com.uber.profiling.transformers.MethodProfilerStaticProxy.collectMethodDuration(\"%s\", \"%s\", durationMillis_java_agent_instrument);}catch(Throwable ex){ex.printStackTrace();}", normalizedClassName, method.getName()) +
                        // "System.out.println(\"Method Executed in ms: \" + durationMillis);" +
                        "}");
            }

            // 整个函数体的执行代码增加了前置和后置处理,实现了耗时的监控
            logger.info("Transformed class method: " + method.getLongName() + ", durationProfiling: " + enableDurationProfiling + ", argumentProfiling: " + argumentsForProfile);
        } catch (Throwable ex) {
            ex.printStackTrace();
            logger.warn("Failed to transform class method: " + method.getLongName(), ex);
        }
    }
}


采集结果

{
    "metricName": "duration.min",
    "processName": "2203@xiaozhideMacBook-Pro.local",
    "appId": null,
    "host": "xiaozhideMacBook-Pro.local",
    "processUuid": "1e580f6e-0493-4e5b-bee2-a61c5f7b097d",
    "metricValue": 894.0,
    "methodName": "publicSleepMethod",
    "className": "com.uber.profiling.examples.HelloWorldApplication",
    "epochMillis": 1536072801037,
    "tag": "mytag"
}
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 158,117评论 4 360
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 66,963评论 1 290
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 107,897评论 0 240
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 43,805评论 0 203
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 52,208评论 3 286
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 40,535评论 1 216
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 31,797评论 2 311
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 30,493评论 0 197
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 34,215评论 1 241
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 30,477评论 2 244
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 31,988评论 1 258
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 28,325评论 2 252
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 32,971评论 3 235
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 26,055评论 0 8
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 26,807评论 0 194
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 35,544评论 2 271
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 35,455评论 2 266

推荐阅读更多精彩内容

  • Android 自定义View的各种姿势1 Activity的显示之ViewRootImpl详解 Activity...
    passiontim阅读 170,563评论 25 707
  • Spring Cloud为开发人员提供了快速构建分布式系统中一些常见模式的工具(例如配置管理,服务发现,断路器,智...
    卡卡罗2017阅读 134,097评论 18 139
  • 1994年7月5号,阳光明媚,微风徐徐,一个难得的好天气!再过三天就是侄女的生日,这样想的时候,突然接到姐姐打来的...
    眉飞色舞07阅读 568评论 19 9
  • 如何整理好内务,这名字一听就是有关住宿的,那到底如何才能整理好内务呢? 首先要保持自己的个人卫生,自己的卫生都保持...
    帅云吞1阅读 5,037评论 0 1
  • 一场秋雨一场寒的深秋 什么都冷了 月冷了月光也冷了 风冷了空气也冷了 行人的路安静休息了 行道的灯竟然也安静休息了...
    窮奇阅读 151评论 0 1