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 durationProfiling, List 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 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 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": "[email protected]",
    "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"
}