Есть java EE приложение, которое крутится в контейнере WildFly. Система уровня интерпрайз. Приложение вендорное, класса WMS — Warehouse Management System.

Есть много кода, периодически у нашей службы технической поддержки возникает желание посмотреть сколько по времени выполнялся тот или иной метод, в любом классе.

Тут нам предстоит взять некий метод processStep, обрамить его с помощью try/catch/finally, и писать в какой-нибудь отдельный файл.

Первое что приходит в голову, что нужно сделать что-то вроде:

public Object processStep(Object object){
long __metricStartTime = System.currentTimeMillis();
try{
 // Основной код метода
}catch(Exception e){
throw e;
}finally {
long __metricsEndTime = System.currentTimeMillis() - __metricStartTime;
log.debug(this.getClass().getName()+"|processStep|"+__metricsEndTime);
}
}

Вместо __metricStartTime, __metricsEndTime может быть какой-нибудь metrics.dropwizard.io . Но это будет отдельная тема, для простоты использую startime/endtime.

В этой статье мы будем изменять класс «на-лету» перед тем как его будет грузить classLoader.

• Вариант с добавлением try/catch/finally вручную, плох тем что мы заранее не знаем какие классы понадобятся для анализа скорости их выполнения;
• Для внесения такого рода изменения придется планировать релиз;
• В нашей системе классов ~ 10К.

Для работы с байт-кодом, я использовал javaassist.

Для доступа к коду я создал агент, прочитав вот эту статью.

Исходный код выглядит так:

import java.lang.instrument.Instrumentation;

public class Agent {
    public static void premain(String agentArgs, Instrumentation instrumentation) {
        instrumentation.addTransformer(new ClassTransformer());
    }
}

Пишем собственный ClassTransformer.

Наш класс трансформер должен определять какой класс нужно менять, а какой можно пропустить.

Для этого я создал json конфиг в котором перечисляю классы и методы, которые я бы хотел инструментировать примерно так:

{
"settings" : 
[
{
	"PackageName" 	: "com.ltm.scm.wms.utils.voice",
	"className" : "VoiceProcessor",
	"Methods" : ["completeTask", "processException"]
}
,
{
	"PackageName" : "com.ltm.scm.wms.utils.voice.dao",
	"className" : "VoiceDAO",
	"Methods" : ["isCompleteTask", "getLocationType"]
},
{
	"PackageName" : "com.ssaglobal.scm.wms.service.drfmanagement",
	"className" : "RFInquiryP1S1",
	"Methods" : ["processStep"]
},
{
	"PackageName" : "ru.ltm.vc.service",
	"className" : "*",
	"Methods" : ["*"]
},
{
	"PackageName" : "ru.ltm.vc.controller",
	"className" : "*",
	"Methods" : ["*"]
}
]
}

* — Все классы в пакете и/или все методы в классе.

Строковые константы класса

    private static final String METRICS_START_TIME_FIELD_SRC = "public static long __metricStartTime;";
    private static final String METRICS_START_TIME_FIELD_INITIALIZE_SRC = "System.currentTimeMillis()";

    private static final String CLASS_METRICS_FIELD_SRC = "public static final ru.ltm.agent.jmx.ClassesMetricsProfiler metricsProfiler;";
    private static final String CLASS_METRICS_FIELD_INITIALIZE_SRC = "new ru.ltm.agent.jmx.ClassesMetricsProfiler()";
    private static final String METRICS_START_TIME_VAR_SRC = "__metricStartTime";
    private static final String METRICS_START_TIME_VAR_INITIALIZE_SRC = "__metricStartTime = System.currentTimeMillis();";
    private static final String METRICS_END_TIME_VAR_SRC = "\", System.currentTimeMillis() - __metricStartTime);";
    private static final String JMX_METHOD = "metricsProfiler.mark2(\"";
    private static final String CATCH_BLOCK_SRC = "{ System.out.println($e); throw $e; }";
    private static final String EXCEPTION_TYPE_SRC = "java.lang.Exception";
    private static final String PACKAGE_DEV = "/";
    private static final String DOT = ".";
    private static final String INFOR_HOME = "c:\\Infor\\";
    private static final Map<String,Set<Settings>> CLASSES_TO_INSTRUMENT = ClassRegistry.getInstance().getClasses();

 @Override
    public byte[] transform(ClassLoader loader, String className, Class redefiningClass, ProtectionDomain domain, byte[] bytes) throws IllegalClassFormatException {
        String clazzName = className.replace(PACKAGE_DEV,DOT);
        if (CLASSES_TO_INSTRUMENT.containsKey(clazzName)) {
            Set<Settings> methodsToInstrument = CLASSES_TO_INSTRUMENT.get(clazzName);
            return transformClass(redefiningClass, bytes, methodsToInstrument);
        }

        return null;
    }

transformClass:

private byte[] transformClass(Class classToTransform, byte[] b, Set<Settings> methodsToInstrument) {
        ClassPool pool = ClassPool.getDefault();
        ClassLoader classLoader = Thread.currentThread().getContextClassLoader();
        pool.appendClassPath(new LoaderClassPath(classLoader));
        CtClass.debugDump = INFOR_HOME;
        CtClass cl = null;
        try {
            cl = pool.makeClass(new java.io.ByteArrayInputStream(b));
            CtField metricsField = CtField.make(CLASS_METRICS_FIELD_SRC, cl);
            cl.addField(metricsField, CtField.Initializer.byExpr(CLASS_METRICS_FIELD_INITIALIZE_SRC));

            CtField starTimeField = CtField.make(METRICS_START_TIME_FIELD_SRC, cl);
            cl.addField(starTimeField, CtField.Initializer.byExpr(METRICS_START_TIME_FIELD_INITIALIZE_SRC));
            CtBehavior[] methods = cl.getDeclaredBehaviors();
            for (int i = 0; i < methods.length; i++) {
                if (methods[i].isEmpty() == false) {
                    changeMethod(methods[i], cl, methodsToInstrument);
                }
            }
            b = cl.toBytecode();
        } catch (Exception e) {
            e.printStackTrace();
        } finally {
            cl.debugWriteFile(INFOR_HOME);
            if (cl != null) {
                cl.detach();
            }
        }
        return b;
    }

Строка CtClass.debugDump = INFOR_HOME;
позволяет посмотреть на класс после его перекомпиляции внутри агента после загрузки. debugDump- Куда сохранить новую версию класса.

  CtField metricsField = CtField.make(CLASS_METRICS_FIELD_SRC, cl);
            cl.addField(metricsField, CtField.Initializer.byExpr(CLASS_METRICS_FIELD_INITIALIZE_SRC));
            CtField starTimeField = CtField.make(METRICS_START_TIME_FIELD_SRC, cl);
            cl.addField(starTimeField, CtField.Initializer.byExpr(METRICS_START_TIME_FIELD_INITIALIZE_SRC));

Эти строки добавляют два поля в класс:

CLASS_METRICS_FIELD_SRC — создание нового поля («public static final ru.ltm.agent.jmx.ClassesMetricsProfiler metricsProfile») и CLASS_METRICS_FIELD_INITIALIZE_SRC — «new ru.ltm.agent.jmx.ClassesMetricsProfiler()» — инициализация.

Строковые константы класса я определил выше по тексту.

Метод который добавляет try/catch/finally:

    private void changeMethod(CtBehavior method, CtClass ctClass, Set<Settings> methodsToInstrument) throws Exception {
        for (Object settingObj : methodsToInstrument.toArray()){
            Settings settings  = (Settings) settingObj;
            List<String> methods = settings.getMethodsToInstrument();
            if (methods.contains(method.getName()) ||
                    ( settings.getMethodsToInstrument().get(0).equalsIgnoreCase("*") &&
                            !method.getName().equalsIgnoreCase("<clinit>") &&
                            !method.getName().startsWith("lambda$")) ){

                String metricName = ctClass.getPackageName() + DOT + ctClass.getSimpleName() + DOT + method.getName();
                method.insertBefore(METRICS_START_TIME_VAR_INITIALIZE_SRC);
                CtClass etype = ClassPool.getDefault().get(EXCEPTION_TYPE_SRC);
                method.addCatch("{ throw $e; }" , etype);
                method.insertAfter( JMX_METHOD + metricName + METRICS_END_TIME_VAR_SRC,true);


            }
        }
    }

JMX_METHOD — Кладёт всё в jmx бины.

В результате получается вот такая штука:



Любой класс или пакет можно замерить без изменений кода вручную.

Через телеграф мы стягиваем jmx бины, и выводим в grafana, и примерно это выглядит вот так:



Ссылка на полную версию кода