Btrace

Btrace是一種java效能觀測的工具，其專案地址為https://github.com/btraceio/btrace

根據開發專案組對於此工具的描述為一種安全的動態java跟蹤工具

其原理是通過連線指定的正在執行的虛擬機器，並根據指令碼對於指定的方法進行位元組碼的替換，導致在執行正常程式碼的過程中獲取並列印需要的資訊。

Btrace環境支援

Btace對於執行的環境有個明確的要求，需要執行在JDK環境中，並且依賴系統引數JAVA_HOME,對此不再進行闡述

Btrace基本使用

在此僅以開源專案dble為例，在dble中由於在優化過程中需要觀察一個查詢各個時間的節點，需要對於每個時間點進行時間的列印和觀測在程式碼中建立了觀測類

/*
 * Copyright (C) 2016-2018 ActionTech.
 * License: http://www.gnu.org/licenses/gpl.html GPL version 2 or higher.
 */

package com.actiontech.dble.btrace.provider;

public class CostTimeProvider {
    public void beginRequest(long id) {
    }

    public void startProcess(long id) {
    }

    public void endParse(long id) {
    }

    public void endRoute(long id) {
    }

    public void resFromBack(long id) {
    }

    public void resLastBack(long id) {

    }

    public void execLastBack(long id) {

    }

    public void startExecuteBackend(long id) {
    }

    public void allBackendConnReceive(long id) {
    }

    public void beginResponse(long id) {
    }

    public void endDelive(long id) {
    }
}
 

在程式碼中每個對應的節點呼叫上述的方法，在這個類中，所有的實現方法都是空，所以在正常執行過程中不會對於專案中的程式碼造成影響。

建立觀測指令碼

/*
 * Copyright (C) 2016-2018 ActionTech.
 * License: http://www.gnu.org/licenses/gpl.html GPL version 2 or higher.
 */

package com.actiontech.dble.btrace.script;


import com.sun.btrace.BTraceUtils;
import com.sun.btrace.Profiler;
import com.sun.btrace.annotations.*;

import java.util.Map;

import static com.sun.btrace.BTraceUtils.Profiling;
import static com.sun.btrace.BTraceUtils.timeNanos;

@BTrace
public class BTraceCostTime {
    private static Map<Long, Long> records = BTraceUtils.Collections.newHashMap();

    @Property
    static Profiler profiler = BTraceUtils.Profiling.newProfiler();

    @OnMethod(
            clazz = "com.actiontech.dble.btrace.provider.CostTimeProvider",
            method = "beginRequest"
    )
    public static void beginRequest(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, long arg) {
        BTraceUtils.Collections.put(records, arg, timeNanos());
    }

    @OnMethod(
            clazz = "com.actiontech.dble.btrace.provider.CostTimeProvider",
            method = "startProcess"
    )
    public static void startProcess(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, long arg) {
        Long ts = BTraceUtils.Collections.get(records, arg);
        if (ts == null) {
            return;
        }
        long duration = timeNanos() - ts;
        Profiling.recordExit(profiler, "request->1.startProcess", duration);
    }

    @OnMethod(
            clazz = "com.actiontech.dble.btrace.provider.CostTimeProvider",
            method = "endParse"
    )
    public static void endParse(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, long arg) {
        Long ts = BTraceUtils.Collections.get(records, arg);
        if (ts == null) {
            return;
        }
        long duration = timeNanos() - ts;
        Profiling.recordExit(profiler, "request->2.endParse", duration);
    }

    @OnMethod(
            clazz = "com.actiontech.dble.btrace.provider.CostTimeProvider",
            method = "endRoute"
    )
    public static void endRoute(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, long arg) {
        Long ts = BTraceUtils.Collections.get(records, arg);
        if (ts == null) {
            return;
        }
        long duration = timeNanos() - ts;
        Profiling.recordExit(profiler, "request->3.endRoute", duration);
    }

    @OnMethod(
            clazz = "com.actiontech.dble.btrace.provider.CostTimeProvider",
            method = "endDelive"
    )
    public static void endDelive(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, long arg) {
        Long ts = BTraceUtils.Collections.get(records, arg);
        if (ts == null) {
            return;
        }
        long duration = timeNanos() - ts;
        Profiling.recordExit(profiler, "request->3.05.endDelive", duration);
    }


    @OnMethod(
            clazz = "com.actiontech.dble.btrace.provider.CostTimeProvider",
            method = "resLastBack"
    )
    public static void resLastBack(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, long arg) {
        Long ts = BTraceUtils.Collections.get(records, arg);
        if (ts == null) {
            return;
        }
        long duration = timeNanos() - ts;
        Profiling.recordExit(profiler, "request->4L.resLastBack", duration);
    }


    @OnMethod(
            clazz = "com.actiontech.dble.btrace.provider.CostTimeProvider",
            method = "execLastBack"
    )
    public static void execLastBack(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, long arg) {
        Long ts = BTraceUtils.Collections.get(records, arg);
        if (ts == null) {
            return;
        }
        long duration = timeNanos() - ts;
        Profiling.recordExit(profiler, "request->5L.execLastBack", duration);
    }


    @OnMethod(
            clazz = "com.actiontech.dble.btrace.provider.CostTimeProvider",
            method = "resFromBack"
    )
    public static void resFromBack(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, long arg) {
        Long ts = BTraceUtils.Collections.get(records, arg);
        if (ts == null) {
            return;
        }
        long duration = timeNanos() - ts;
        Profiling.recordExit(profiler, "request->4.resFromBack", duration);
    }

    @OnMethod(
            clazz = "com.actiontech.dble.btrace.provider.CostTimeProvider",
            method = "startExecuteBackend"
    )
    public static void startExecuteBackend(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, long arg) {
        Long ts = BTraceUtils.Collections.get(records, arg);
        if (ts == null) {
            return;
        }
        long duration = timeNanos() - ts;
        Profiling.recordExit(profiler, "request->5.startExecuteBackend", duration);
    }


    @OnMethod(
            clazz = "com.actiontech.dble.btrace.provider.CostTimeProvider",
            method = "allBackendConnReceive"
    )
    public static void allBackendConnReceive(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, long arg) {
        Long ts = BTraceUtils.Collections.get(records, arg);
        if (ts == null) {
            return;
        }
        long duration = timeNanos() - ts;
        Profiling.recordExit(profiler, "request->5.1.allBackendConnReceive", duration);
    }

    @OnMethod(
            clazz = "com.actiontech.dble.btrace.provider.CostTimeProvider",
            method = "beginResponse"
    )
    public static void beginResponse(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, long arg) {
        Long ts = BTraceUtils.Collections.get(records, arg);
        if (ts == null) {
            return;
        }
        long duration = timeNanos() - ts;
        BTraceUtils.Collections.remove(records, arg);
        Profiling.recordExit(profiler, "request->6.response", duration);
    }

    @OnTimer(4000)
    public static void print() {
        BTraceUtils.Profiling.printSnapshot("profiling:", profiler);
    }
}
 

通過觀測指令碼的程式碼我們可以看到，事實上通過btrace提供的標籤屬性指定在指令碼BTraceCostTime中的屬性替換掉指定clazz裡面的指定method方法，在正常程式碼執行到CostTimeProvider中的對應方法時，會被替換呼叫到BTraceCostTime的對應方法中，並進行統計通過定時方法print週期性的打印出來

其中呼叫的方法為

Btrace {java_pid} BTraceCostTime.java

Btrace非安全模式

在一般過程中在btrace的指令碼編寫時只能使用btrace允許的方法，(https://github.com/btraceio/btrace/wiki/Trace-Scripts)基本上就是BTraceUtils提供的對應方法，非常有限，並且會禁止呼叫其他物件的方法，但是有的時候我們對於btrace的應用會有特殊的場景，需要在替換的方法裡面執行一些更加符合我們實際需要的程式碼。

這個時候就可以開啟btarce的unsafe模式進行操作，這個模式有兩個主要的修改點

1 修改btrace指令碼，加入unsafe引數

${JAVA_HOME}/bin/java -Dcom.sun.btrace.unsafe=true  -cp ${BTRACE_HOME}/build/btrace-client.jar:${TOOLS_JAR}:/usr/share/lib/java/dtrace.jar com.sun.btrace.client.Main $*

2 在指令碼中註明unsafe引數

在類宣告之前使用btrace提供的標籤進行宣告@BTrace(unsafe = true)