一开始我对 javaagent 的概念也比较陌生，后面跟着别人了解到 字节码插桩 之后, 我才了解到这个东西的强大. java 是依赖 JVM 运行的. 我们编写的 java 代码会被编译器编译为 .class 文件. 而.class 文件里面都是一些 JVM 指令码. (最开始我以为是直接编译为机器语言) , 然后解释执行,

javaagent 是java1.5之后引入的特性，其主要作用是在class 被加载之前对其拦截, 以便于我们修改原来的字节码的执行逻辑. 接下来我们看看如何使用 javaagent

javaagent 注意事项

javaagent 最后展现形式是一个 Jar 包，有以下特性:

1.必须 META-INF/MANIFEST.MF中指定 Premain-Class 设定启agent启动类。

2.在启类需写明启动方法 public static void premain(String arg, Instrumentation instrumentation);

3.不可直接运行，只能通过 jvm 参数-javaagent:xxx.jar 附着于其它 jvm 进程运行。

接下来我们简单的演示一下 javaagent 的使用. 首先创建一个 maven 项目, 名字叫做 MyAgent

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>org.example</groupId>
    <artifactId>MyAgent</artifactId>
    <version>0.1.RELEASE</version>

    <dependencies>
        <!-- 引入 javassist 是为了后面演示修改 .class 的功能 -->
        <dependency>
            <groupId>org.javassist</groupId>
            <artifactId>javassist</artifactId>
            <version>3.25.0-GA</version>
        </dependency>
    </dependencies>

    <build>
        <plugins>
            <!-- 使用这个插件进行打包时, 可以将依赖包的源码也打入到 jar 中 -->
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-assembly-plugin</artifactId>
                <version>2.5.5</version>
                <configuration>
                    <archive>
                        <manifestFile>src/main/resources/META-INF/MANIFEST.MF</manifestFile>
                    </archive>
                    <descriptorRefs>
                        <descriptorRef>jar-with-dependencies</descriptorRef>
                    </descriptorRefs>
                </configuration>
            </plugin>
          
            <!-- 使用这个插件在 IDEA 中就不需要设置编译环境和依赖 jdk 版本了 -->
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-compiler-plugin</artifactId>
                <version>2.3.1</version>
                <configuration>
                    <source>1.8</source>
                    <target>1.8</target>
                    <encoding>utf8</encoding>
                </configuration>
            </plugin>
        </plugins>
    </build>
</project>

首先在 src/main/resources 下创建一下 META-INF/MANIFEST.MF, 然后在编译插件中指定指向这个文件. 文件内容如下:

Manifest-Version: 1.0
Premain-Class: org.example.bytecode.AgentApplication
Can-Redefine-Classes: true
Can-Retransform-Classes: true

这里的 Premain-Class 需要指定我们自己定义的 javaagent 启动类. 接下来我们看一下 javaagnet 启动类怎么写

AgentApplication

package com.tameti.bytecode;

import javassist.CannotCompileException;
import javassist.ClassPool;
import javassist.CtClass;
import javassist.CtMethod;

import java.lang.instrument.Instrumentation;

/**
 * 字节码插桩: 基于 javassist.
 */
public class AgentApplication {

    // java-agent 入口方法
    public static void premain(String arg, Instrumentation instrumentation) {

        // 通过 instrumentation 拿到加载类的信息
        instrumentation.addTransformer((loader, className, classBeingRedefined, protectionDomain, classfileBuffer) -> {
            // 打印加载类的信息
            System.out.println(className);
            return null;
        });
    }

}

接下来通过 maven 插件打包编译

接下来我们启动随意启动一个 jar 包, 并且携带上这个 javaagent 包. 我们就可以了解到这个 jar 包到底加载了什么类

这里我们就通过 javaagent 拿到了加载的所有类名称. 这里我们可以看到 java 类名称是以 / 作为分割符. 所以我们需要对 / 进行替换才能得到真正的类名称. 现在我们拿到类名称后, 我们就可以通过 javassist 拿到所有类的字节码. 然后我们就可以对方法进行增强, 先来一个简单的功能. 记录一个方法的时间消耗. 代码如下:

package com.tameti.bytecode;

import javassist.*;

import java.lang.instrument.Instrumentation;

/**
 * 字节码插桩: 基于 javassist.
 */
public class AgentApplication {
    public static String name(CtMethod method) {
        // 获取方法所在的实体类的名称
        String className = method.getDeclaringClass().getName();
        StringBuffer joiner = new StringBuffer(className).append("::").append(method.getName()).append("(");

        try {
            // 获取方法的所有参数类型
            CtClass[] parameterTypes = method.getParameterTypes();
            // 拼接内容 类路径::方法名(
            for (int i = 0; i < parameterTypes.length; i++) {
                CtClass parameterType = parameterTypes[i];
                joiner.append(parameterType.getName());
                if (i != parameterTypes.length - 1) {
                    joiner.append(",");
                }
            }
        } catch (NotFoundException e) {
            e.printStackTrace();
        }

        // 拼接内容 )
        return joiner.append(")").toString();
    }

    // java-agent 入口方法
    public static void premain(String arg, Instrumentation instrumentation) {

        final ClassPool pool = ClassPool.getDefault();

        // 基于 javassist 实现在运行时修改 class 字节码
        instrumentation.addTransformer((loader, className, classBeingRedefined, protectionDomain, classfileBuffer) -> {
            try {
                // 拿到替换后的名称
                String javaClassName = className.replace("/", ".");
                // 拿到字节码
                CtClass ctClass = pool.getCtClass(javaClassName);
                CtClass stringClass = pool.getCtClass("java.lang.String");

                // 如果这个类是一个接口. 那么我们就不进行代理了
                if (!ctClass.isInterface()) {

                    // 拿到里面的所有方法
                    for (CtMethod method : ctClass.getDeclaredMethods()) {
                        // 如果这个方法不是一个 abstract 方法并且也不上一个 native 方法, 我们才进行代理
                        if (!Modifier.isAbstract(method.getModifiers()) && !Modifier.isNative(method.getModifiers())) {
                            
                            // 这里我们也可以直接插入一段代码进去, 写法如下:
                            // StringBuilder sb = new StringBuidler();
                            // sb.append("{") // 如果这个方法包含多行内容并且要使用setBody替换方法体, 必须加 "{}" 
                            // sb.append("long _start = System.nanoTime();\n");
                            // sb.append("$_ = $proceed($$);\n"); // 调用原来的代码
                            // sb.append("System.out.println(\"方法耗时:\" + System.nanoTime - _start + \"ns\")");
                            // sb.append("}");
                            
                            // ExprEditor editor = new ExprEditor() {
                            //    @Override
                            //    public void edit(MethodCall methodCall) throws CannotCompileException {
                            //        methodCall.replace(source.toString());
                            //     }
                            // };
                            // method.instrument(editor);


                            // 拿到方法的唯一标识. 类名称.方法名称(方法参数类型...)
                            String methodName = name(method);

                            // 插入 _startTime 到局部变量表
                            method.addLocalVariable("_startTime", CtClass.longType);
                            // 插入 _methodName 到局部变量表, 我们的名称尽量使用 _ 开头, 避免和原来的变量发生同名冲突
                            method.addLocalVariable("_methodName", stringClass);

                            // 直接插入代码块, 这里插入到方法执行前的位置
                            method.insertBefore("_startTime = System.currentTimeMillis();");
                            method.insertBefore("_methodName = \"" + methodName + "\";");

                            // 直接插入代码块, 这里插入到方法执行后的位置
                            method.insertAfter("System.out.println(\"方法 [\" + _methodName + \"] 运行耗时:\" + (System.currentTimeMillis() - _startTime)/1000 + \"ms\");");
                        }
                    }
                }

                // 返回修改后的字节码
                return ctClass.toBytecode();
            } catch (Exception e) {
                System.err.println("字节码增强失败, 当前失败类名字是:" + className + ", 具体失败原因:" + e.getMessage());
            }
            return null;
        });
    }
}

运行一个 jar 包, 携带我们的增强包

这里我们发现它对所有的类中的可增强的方法都进行了增强, 打印处理每隔方法调用的耗时. 这里我们是使用 javassist 直接修改字节码来实现的. 其实我们还可以通过另外一个东西 bytebuddy 来实现, 它比 javassist 用起来更友好. 我们来看看实现相同的功能, bytebuddy 需要怎么写, 首先贴出 dependency 内容

<dependency>
    <groupId>net.bytebuddy</groupId>
    <artifactId>byte-buddy</artifactId>
    <version>1.8.20</version>
</dependency>
<dependency>
    <groupId>net.bytebuddy</groupId>
    <artifactId>byte-buddy-agent</artifactId>
    <version>1.8.20</version>
</dependency>

统计方法耗时的核心方法

package com.tameti.bytecode;

import net.bytebuddy.implementation.bind.annotation.Origin;
import net.bytebuddy.implementation.bind.annotation.RuntimeType;
import net.bytebuddy.implementation.bind.annotation.SuperCall;

import java.lang.reflect.Method;
import java.util.concurrent.Callable;

public class MethodCostTime {

    @RuntimeType
    public static Object intercept(@Origin Method method, @SuperCall Callable<?> callable) throws Exception {
        long start = System.currentTimeMillis();
        try {
            return callable.call();
        } finally {
            System.out.println(method + "方法耗时:" + (System.currentTimeMillis() - start) + "ms");
        }
    }

}

然后是 premainClass 类配置, 需要把这个耗时方法统计类注入进去使用

package com.tameti.bytecode;

import net.bytebuddy.agent.builder.AgentBuilder;
import net.bytebuddy.description.type.TypeDescription;
import net.bytebuddy.dynamic.DynamicType;
import net.bytebuddy.implementation.MethodDelegation;
import net.bytebuddy.matcher.ElementMatchers;
import net.bytebuddy.utility.JavaModule;

import java.lang.instrument.Instrumentation;

/**
 * 字节码插桩: 基于 javassist.
 */
public class AppAgent {

    // java-agent 入口方法
    public static void premain(String arg, Instrumentation instrumentation) {
        AgentBuilder.Transformer transformer = new AgentBuilder.Transformer() {
            @Override
            public DynamicType.Builder<?> transform(DynamicType.Builder<?> builder, TypeDescription typeDescription, ClassLoader classLoader, JavaModule javaModule) {
                return builder
                        // 拦截所有方法
                        .method(ElementMatchers.any())
                        // 委托给处理类处理
                        .intercept(MethodDelegation.to(MethodCostTime.class));
            }
        };

        // 创建一个过滤规则
        AgentBuilder.Listener listener = new AgentBuilder.Listener() {
            /**
             * 在提供给转换器的类型上调用。
             *
             * @param typeName      插入指令的类型的二进制名称。
             * @param classLoader   正在加载此类型的类加载器
             * @param module        检测类型的模块或{@code null}（如果当前VM不支持模块）。
             * @param loaded        {@code true} 如果类型已加载。
             */
            @Override
            public void onDiscovery(String typeName, ClassLoader classLoader, JavaModule module, boolean loaded) {

            }

            /**
             * 在成功应用转换之前调用。
             *
             * @param typeDescription   正在转换的类型。
             * @param classLoader       加载此类型的类加载器。
             * @param module            转换类型的模块或 {@code null}（如果当前VM不支持模块）。
             * @param loaded            {@code true} 如果类型已加载。
             * @param dynamicType       创建的动态类型。
             */
            @Override
            public void onTransformation(TypeDescription typeDescription, ClassLoader classLoader, JavaModule module, boolean loaded, DynamicType dynamicType) {

            }

            /**
             * 当类型未转换但被忽略时调用。
             *
             * @param typeDescription    转换时忽略的类型。
             * @param classLoader        加载此类型的类加载器。
             * @param module             如果当前VM不支持模块，则忽略类型的模块或{@code null}。
             * @param loaded             {@code true}如果类型已加载。
             */
            @Override
            public void onIgnored(TypeDescription typeDescription, ClassLoader classLoader, JavaModule module, boolean loaded) {

            }

            /**
             * 在转换过程中发生错误时调用。
             *
             * @param typeName      插入指令的类型的二进制名称。
             * @param classLoader   加载此类型的类加载器。
             * @param module        插入指令的类型的模块或{@code null}（如果当前VM不支持模块）。
             * @param loaded        {@code true}如果类型已加载。
             * @param throwable     发生错误。
             */
            @Override
            public void onError(String typeName, ClassLoader classLoader, JavaModule module, boolean loaded, Throwable throwable) {

            }

            /**
             * 在尝试加载类之后调用，与类的处理无关。
             *
             * @param typeName      插入指令的类型的二进制名称。
             * @param classLoader   加载此类型的类加载器。
             * @param module        插入指令的类型的模块或{@code null}（如果当前VM不支持模块）。
             * @param loaded        {@code true}如果类型已加载。
             */
            @Override
            public void onComplete(String typeName, ClassLoader classLoader, JavaModule module, boolean loaded) {

            }
        };

        // 注入进去
        new AgentBuilder.Default().type(ElementMatchers.any()).transform(transformer).with(listener).installOn(instrumentation);
    }
}

然后编译运行代码

实现的效果是一样的, 并且整个逻辑看起来更加清晰了.

基于 javaagent 实现定时内存日志打印

首先, 编写一个打印 JVM 相关信息的类

package com.tameti.bytecode;

import java.lang.management.GarbageCollectorMXBean;
import java.lang.management.ManagementFactory;
import java.lang.management.MemoryMXBean;
import java.lang.management.MemoryUsage;
import java.util.Arrays;
import java.util.List;

public class VMInfo {
    // 定义单位 MB, 1MB = 1024 * 1024
    private static final long MB = 1024 * 1024;

    /**
     * 打印 JVM 堆内存和非堆内存的信息
     */
    public static void memoryInfo() {
        MemoryMXBean memory = ManagementFactory.getMemoryMXBean();
        MemoryUsage usage = memory.getHeapMemoryUsage();

        // 初始化堆内存大小
        long initHeapSize = usage.getInit() / MB;
        // 最大堆内存大小
        long maxHeapSize = usage.getMax() / MB;
        // 已使用堆内存大小
        long useHeapSize = usage.getUsed() / MB;
        // 已经提交的堆内存大小
        long commitHeapSize = usage.getCommitted() / MB;
        // 内存使用百分比
        double scale = (double)(usage.getUsed() * 100) / usage.getCommitted();

        System.out.println("[监控-虚拟机堆内存信息]: 初始化内存:" + initHeapSize + "M     最大内存:" + maxHeapSize + "M     已使用内存:" + useHeapSize + "M    已提交内存:" + commitHeapSize + "M " + "   比例:" + scale + "%");

        MemoryUsage usage1 = memory.getNonHeapMemoryUsage();

        long initNoHeapSize = usage1.getInit() / MB;
        long maxNoHeapSize = usage1.getMax() / MB;
        long useNoHeapSize = usage1.getUsed() / MB;
        long commitNoHeapSize = usage1.getCommitted() / MB;
        double scale1 = (double) (usage1.getUsed() * 100) / usage1.getCommitted();

        System.out.println("[监控-虚拟机非堆内存信息]: 初始化内存:" + initNoHeapSize + "M     最大内存:" + maxNoHeapSize + "M     已使用内存:" + useNoHeapSize + "M    已提交内存:" + commitNoHeapSize + "M " + "   比例:" + scale1 + "%");
    }


    /**
     * 打印 GC 信息
     */
    public static void gcInfo() {
        // 拿到所有的垃圾收集器对象
        List<GarbageCollectorMXBean> gcBeans = ManagementFactory.getGarbageCollectorMXBeans();
        for (GarbageCollectorMXBean gc : gcBeans) {
            String info = String.format("垃圾收集器名称: %s\t 回收次数:%s\t 耗时:%sms\t 垃圾收集器针对区域:%s", gc.getName(), gc.getCollectionCount(), gc.getCollectionTime(), Arrays.deepToString(gc.getMemoryPoolNames()));
            System.out.println(info);
        }
    }

}

然后再 premainClass 中创建一个异步的定时任务, 定时执行这个类中的方法

package com.tameti.bytecode;

import java.lang.instrument.Instrumentation;
import java.util.concurrent.Executors;
import java.util.concurrent.TimeUnit;

/**
 * 字节码插桩: 基于 javassist.
 */
public class AgentApplication {

    // java-agent 入口方法
    public static void premain(String arg, Instrumentation instrumentation) {
        // 开启一个线程
        Executors.newScheduledThreadPool(1).scheduleAtFixedRate(new Runnable() {
            public void run() {
                VMInfo.memoryInfo();
                VMInfo.gcInfo();
                System.out.println();
            }
        // 每隔 5S 执行一次
        }, 0, 5000, TimeUnit.MILLISECONDS);
    }
}

接下来启动一个 SpringBoot 并且再 VMOptions 中添加 -javaagent:agent.jar 来看看这个增强包的效果

感觉这个东西逼格满满呀. 我们还可以再每行日志打印前, 打印一个时间来区分 JVM 信息的具体时间

现在扩展一下功能, 基于 javassist + javaagent 实现一个打印方法具体入参的功能. 这里我们的实现思路是. 通过 javaagent 的执行顺序得到每个方法的行参名称, 然后通过 javassist 把打印形参名称的方法 System.out.println 语句注入进去. 至于运行时具体传入的实参内容. 我们可以通过 javassist 的 $args 拿到, https://blog.csdn.net/weixin_44231940/article/details/118570497 这篇文章里面介绍了 javassist 实现自定义动态代理, 里面有介绍关于如何拿到运行时传入的参数的方法. 这里我们要针对字节码补充的代码如下:

修饰符 返回值 方法(参数列表) {
    java.lang.Object[] _variables = $args;
    java.lang.String[] _names = java.util.Arrays.asList("参数名1", "参数名2",...);
    System.out.print("方法: " + _methodName + ", 传入参数列表: [");
    for (int i = 0; i < _variablels.length; i++) {
        java.lang.Object _variableValue = _variables[i];
        java.lang.String _paramName = _names[i];
        // 过滤掉我们自己传入的参数
        if (!"_methodName".equals(_paramName)) {
            System.out.print(_paramName + ":" + _variableValue.toString());
        }
    }
    System.out.println("]");

    ... 不动原来的代码
}

我们在字节码层面为每一个方法都添加一个这样的前缀逻辑, 这样方法在每次运行的时候都会打印出一段执行时传入参数的名称和值的信息, 这样我们基本上不需要在原来的代码上增加 log.info 就可以实现打印参数的功能. 这里我是对所有方法进行增强, 实际情况中可以针对某个类的某个方法进行单独增强

package com.tameti.bytecode;

import com.google.common.io.Files;
import javassist.ClassPool;
import javassist.CtClass;
import javassist.CtMethod;
import javassist.NotFoundException;
import javassist.bytecode.CodeAttribute;
import javassist.bytecode.LocalVariableAttribute;
import javassist.bytecode.MethodInfo;

import java.io.File;
import java.lang.instrument.Instrumentation;
import java.lang.reflect.Modifier;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.concurrent.Executors;
import java.util.concurrent.TimeUnit;

/**
 * 字节码插桩: 基于 javassist.
 */
public class AgentApplication {
    private static final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss");

    public static String name(CtMethod method) {
        // 获取方法所在的实体类的名称
        String className = method.getDeclaringClass().getName();
        StringBuffer joiner = new StringBuffer(className).append("::").append(method.getName()).append("(");

        try {
            // 获取方法的所有参数类型
            CtClass[] parameterTypes = method.getParameterTypes();
            // 拼接内容 类路径::方法名(
            for (int i = 0; i < parameterTypes.length; i++) {
                CtClass parameterType = parameterTypes[i];
                joiner.append(parameterType.getName());
                if (i != parameterTypes.length - 1) {
                    joiner.append(",");
                }
            }
        } catch (NotFoundException e) {
            e.printStackTrace();
        }

        // 拼接内容 )
        return joiner.append(")").toString();
    }

    /**
     * 基于字节码方法来得到方法中的参数名称
     *
     * @param cm
     * @return
     */
    public static String[] getVariables(CtMethod cm) {
        CtClass cc = cm.getDeclaringClass();
        MethodInfo methodInfo = cm.getMethodInfo();
        CodeAttribute codeAttribute = methodInfo.getCodeAttribute();
        LocalVariableAttribute attr = (LocalVariableAttribute) codeAttribute.getAttribute(LocalVariableAttribute.tag);
        if (attr == null) {
            throw new RuntimeException(cc.getName());
        }

        String[] paramNames = null;
        try {
            paramNames = new String[cm.getParameterTypes().length];
        } catch (NotFoundException e) {
            e.printStackTrace();
        }
        // this 所在的位置
        int pos = -1;
        for (int i = 0; i < attr.tableLength(); i++) {
            if (attr.variableName(i).equals("this")) {
                pos = i + 1;
            }
        }

        for (int i = 0; i < paramNames.length; i++) {
            paramNames[i] = attr.variableName(i + pos);
        }
        return paramNames;
    }


    // java-agent 入口方法
    public static void premain(String arg, Instrumentation instrumentation) {
        final ClassPool pool = ClassPool.getDefault();

        instrumentation.addTransformer((loader, className, classBeingRedefined, protectionDomain, classfileBuffer) -> {
            try {
                // 拿到替换后的名称
                String javaClassName = className.replace("/", ".");

                // 拿到字节码
                CtClass ctClass = pool.getCtClass(javaClassName);

                // 如果这个类是一个接口. 那么我们就不进行代理了
                if (javaClassName.equals("com.code.runner.web.HttpController")) {
                      // 拿到里面的所有方法
                    for (CtMethod method : ctClass.getDeclaredMethods()) {
                        // 如果这个方法不是一个 abstract 方法并且也不上一个 native 方法, 我们才进行代理
                        if (!Modifier.isAbstract(method.getModifiers()) && !Modifier.isNative(method.getModifiers())) {
                            // 拿到方法的唯一标识. 类名称.方法名称(方法参数类型...)
                            String methodName = name(method);
                            // 插入 _methodName 到局部变量表, 我们的名称尽量使用 _ 开头, 避免和原来的变量发生同名冲突
                            // method.addLocalVariable("method__proxy", stringClass);

                            // 使用 javassist 从局部变量表中拿到方法的参数名称
                            String[] variables = getVariables(method);

                            StringBuilder sb = new StringBuilder();
                            sb.append("java.lang.String method__proxy = \"").append(methodName).append("\";");
                            sb.append("System.out.print(\"方法:\" + method__proxy + \", 传入参数列表: [\");");

                            if (variables.length > 0) {
                                sb.append("java.lang.Object[] values__proxy = $args;");
                                StringBuilder params = new StringBuilder();
                                for (int i = 0; i < variables.length; i++) {
                                    params.append("\"").append(variables[i]).append("\"");
                                    if (i != variables.length - 1) {
                                        params.append(",");
                                    }
                                }
                                sb.append("java.lang.String[] names__proxy = new java.lang.String[]{").append(params.toString()).append("};");
                                sb.append("for (int i = 0; i < values__proxy.length; i++) {");
                                sb.append("    java.lang.Object value_proxy = values__proxy[i];");
                                sb.append("    java.lang.String name_proxy = names__proxy[i];");
                                sb.append("    System.out.print(name_proxy + \":\" + value_proxy.toString()); ");
                                sb.append("    if (i != values_proxy.length) {");
                                sb.append("        System.out.print(\",\")");
                                sb.append("    }");
                                sb.append("}");
                            }

                            sb.append("System.out.println(\"]\");");

                            System.out.println(sb.toString());
                            // 直接插入代码块, 这里插入到方法执行前的位置
                            method.insertBefore(sb.toString());
                            // 直接插入代码块, 这里插入到方法执行后的位置
                        }
                    }
                }

                byte[] bytes =  ctClass.toBytecode();
                return bytes;

            } catch (Exception e) {
                 e.printStackTrace();
            }

            return null;
        });

        // 开启一个线程
        Executors.newScheduledThreadPool(1).scheduleAtFixedRate(new Runnable() {
            public void run() {
                System.out.println("JVM 当前统计时间:" + sdf.format(new Date()));
                VMInfo.memoryInfo();
                VMInfo.gcInfo();
                System.out.println();
            }
        // 每隔 5S 执行一次
        }, 0, 5000, TimeUnit.MILLISECONDS);
    }
}

但是, 上面的方法会存在过多的问题, 以至于我后面直接把它推翻重做. 但是想法还是有点参考性的. 优化思路如下:

基于原来的方法拷贝出一个新的方法, 叫做 agent$方法名(参数列表), 然后重写原来的方法. 最后将我们增强的代码写入到重写后的原来的方法中, 最后调用基于原来的放啊拷贝出的新方法. 原理如下:

public class A {
    private String p;

    public void hello(String a, String b) {
        System.out.println(a + b);
    }    

    public String test() {
        return p;
    }
}

 对 A 类进行插桩后的源码如下:

public class A {
    private String p;

    public void hello(String a, String b) {
        java.util.ArrayList values = java.util.Arrays.asList(a, b);
        java.util.ArrayList names = java.util.Arrays.asList("参数名1", "参数名2",...);
        System.out.print("方法: A::hello, 传入参数列表: [");
        for (int i = 0; i < values.size(); i++) {
        	java.lang.Object value = values.get(i);
        	java.lang.String name = names.get(i);
            System.out.print(name + ":" + value.toString());
        }
    	System.out.println("]");
    	this.agent$hello($$);
    }    

    public void agent$hello(String a, String b) {
    	System.out.println(a + b);
    }

    public String test() {
        java.util.ArrayList values = java.util.Arrays.asList(a, b);
        java.util.ArrayList names = java.util.Arrays.asList("参数名1", "参数名2",...);
        System.out.print("方法: A::hello, 传入参数列表: [");
        for (int i = 0; i < values.size(); i++) {
        	java.lang.Object value = values.get(i);
        	java.lang.String name = names.get(i);
            System.out.print(name + ":" + value.toString());
        }
    	System.out.println("]");
    	return (String) this.agent$test($$);
    }

    public String agent$test() {
		return p;
    }
}

这样的设计有个好处就是, 插入的代码和原来的代码逻辑进行分离了, 当然, 变量还是存在冲突的可能. 但是我们可以手动避免这样的冲突. 

上面的例子只是一个简单的 DEMO, 现在我们要对 WEB 应用进行切面, 统计每一次请求的信息. 我们看一下要怎么写.  首先我们需要监控 javax.servlet.http.HttpServlet 中的 service(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse) 方法.

package com.tameti.bytecode;

import javassist.ClassPool;
import javassist.CtClass;
import javassist.CtMethod;
import javassist.LoaderClassPath;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.lang.instrument.ClassFileTransformer;
import java.lang.instrument.IllegalClassFormatException;
import java.lang.instrument.Instrumentation;
import java.security.ProtectionDomain;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.Enumeration;

/**
 * 字节码插桩: 基于 javassist.
 */
public class AgentApplication implements ClassFileTransformer {
    public static final ClassPool pool = ClassPool.getDefault();
    public static final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss");

    public static void begin(HttpServletRequest request, HttpServletResponse response) {
        // 会话id
        String sessionId = request.getSession().getId();
        // 会话发起的地址信息
        String requestAddress = request.getRemoteAddr();
        // 会话请求的资源路径
        String requestUrl = request.getRequestURI();

        StringBuilder sb = new StringBuilder("{");

        // 请求头信息
        Enumeration<String> headerNames = request.getHeaderNames();
        while (headerNames.hasMoreElements()) {
            String h = headerNames.nextElement();
            String v = request.getHeader(h);
            sb.append("\"").append(h).append("\":\"").append(v).append("\",");
        }
        if (sb.length() > 1) {
            sb = new StringBuilder(sb.substring(0, sb.length() - 1));
        }
        sb.append("}");

        String header = sb.toString();

        // 请求携带参数
        sb = new StringBuilder("{");

        Enumeration<String> parameterNames = request.getParameterNames();
        while (parameterNames.hasMoreElements()) {
            String p = parameterNames.nextElement();
            String v = request.getParameter(p);
            sb.append("\"").append(p).append("\":\"").append(v).append("\",");
        }
        if (sb.length() > 1) {
            sb = new StringBuilder(sb.substring(0, sb.length() - 1));
        }

        sb.append("}");
        String method = request.getMethod();
        String params = sb.toString();

        // 请求到达时间
        String requestTime = sdf.format(new Date());
        request.setAttribute("_proxy$requestTime", System.currentTimeMillis());
        System.out.println("会话: " + sessionId + " 开始了, 请求是由 " + requestAddress + " 发起的, 发起时间是: " + requestTime + ", 请求方式为: " + method + ", 请求的资源路径是: " + requestUrl + ".");
        System.out.println("会话: " + sessionId + " 的请求头信息是: " + header + ", 携带参数为: " + params);
    }

    public static void end(HttpServletRequest request, HttpServletResponse response) {
        String sessionId = request.getSession().getId();
        long endTime = (long) request.getAttribute("_proxy$requestTime");
        System.out.println("会话: " + sessionId + " 结束了, 本次请求总共耗时:" + (System.currentTimeMillis() - endTime) + "ms");
    }

    // java-agent 入口方法
    public static void premain(String arg, Instrumentation instrumentation) {
        instrumentation.addTransformer(new AgentApplication());
    }

    @Override
    public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined, ProtectionDomain protectionDomain, byte[] classfileBuffer) throws IllegalClassFormatException {
        String finalClassName = className.replace("/", ".");
        try {
            // 通过监控 HttpServlet 的 service(HttpServletRequest, HttpServletResponse) 来完成请求信息统计
            if (finalClassName.equals("javax.servlet.http.HttpServlet")) {
                // 将当前的 classpath 加入到 classloader 中
                pool.insertClassPath(new LoaderClassPath(loader));
                CtClass servletClass = pool.getCtClass(finalClassName);
                CtClass[] params = new CtClass[]{
                        pool.get("javax.servlet.http.HttpServletRequest"),
                        pool.get("javax.servlet.http.HttpServletResponse")
                };

                CtMethod service = servletClass.getDeclaredMethod("service", params);
                service.insertBefore("com.tameti.bytecode.AgentApplication.begin($$);");
                service.insertAfter("com.tameti.bytecode.AgentApplication.end($$);");
                return servletClass.toBytecode();
            }

        } catch (Exception e) {
            System.err.println(e.getMessage());
        }
        return new byte[0];
    }

}

现在我用浏览器发起一次请求到 springboot 中, 在启动 springboot 的时候添加监听进去

http://localhost:8080/hello?name=dawdawd&jx=dnwakjdb&auth=123&token=kjdbawjkda

控制台输出

会话: 2586C404FE6EA9DE90A54DFA92EDD02D 开始了, 请求是由 0:0:0:0:0:0:0:1 发起的, 发起时间是: 2021-07-15 09:48:39, 请求方式为: GET, 请求的资源路径是: /hello.
会话: 2586C404FE6EA9DE90A54DFA92EDD02D 的请求头信息是: {"host":"localhost:8080","connection":"keep-alive","sec-ch-ua":"" Not;A Brand";v="99", "Google Chrome";v="91", "Chromium";v="91"","sec-ch-ua-mobile":"?0","upgrade-insecure-requests":"1","user-agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.124 Safari/537.36","accept":"text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9","sec-fetch-site":"none","sec-fetch-mode":"navigate","sec-fetch-user":"?1","sec-fetch-dest":"document","accept-encoding":"gzip, deflate, br","accept-language":"zh-CN,zh;q=0.9","cookie":"Idea-39b9dd95=bd61abab-a6f5-4866-aab2-901cf43d0220"}, 携带参数为: {"name":"dawdawd","jx":"dnwakjdb","auth":"123","token":"kjdbawjkda"}
会话: 2586C404FE6EA9DE90A54DFA92EDD02D 结束了, 本次请求总共耗时:63ms
会话: 2586C404FE6EA9DE90A54DFA92EDD02D 开始了, 请求是由 0:0:0:0:0:0:0:1 发起的, 发起时间是: 2021-07-15 09:48:39, 请求方式为: GET, 请求的资源路径是: /favicon.ico.
会话: 2586C404FE6EA9DE90A54DFA92EDD02D 的请求头信息是: {"host":"localhost:8080","connection":"keep-alive","sec-ch-ua":"" Not;A Brand";v="99", "Google Chrome";v="91", "Chromium";v="91"","sec-ch-ua-mobile":"?0","user-agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.124 Safari/537.36","accept":"image/avif,image/webp,image/apng,image/svg+xml,image/*,*/*;q=0.8","sec-fetch-site":"same-origin","sec-fetch-mode":"no-cors","sec-fetch-dest":"image","referer":"http://localhost:8080/hello?name=dawdawd&jx=dnwakjdb&auth=123&token=kjdbawjkda","accept-encoding":"gzip, deflate, br","accept-language":"zh-CN,zh;q=0.9","cookie":"Idea-39b9dd95=bd61abab-a6f5-4866-aab2-901cf43d0220; JSESSIONID=2586C404FE6EA9DE90A54DFA92EDD02D"}, 携带参数为: {}
会话: 2586C404FE6EA9DE90A54DFA92EDD02D 结束了, 本次请求总共耗时:15ms

可以看到, 浏览器一共发起了两次请求, 一次是 /hello, 另外一次是 /favicon.ico. 当然, 只是用控制台简单的打印并不能说明什么, 如果我们要对请求进行分析的话, 那么我们需要将很多请求的信息进入持久化集中存储, 这样才能挖掘出数据背后的意义. 接下来我们就要将请求数据进入入库处理. 数据库的话, 我们就选择 mysql 吧

首先针对采集信息进行一个类的抽象, 引入依赖, 定义实体类

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>org.example</groupId>
    <artifactId>MyAgent</artifactId>
    <version>1.0-SNAPSHOT</version>

    <dependencies>
        <dependency>
            <groupId>org.javassist</groupId>
            <artifactId>javassist</artifactId>
            <version>3.25.0-GA</version>
        </dependency>
        <dependency>
            <groupId>javax.servlet</groupId>
            <artifactId>javax.servlet-api</artifactId>
            <version>3.1.0</version>
            <scope>provided</scope>
        </dependency>
        <dependency>
            <groupId>org.projectlombok</groupId>
            <artifactId>lombok</artifactId>
            <version>1.18.20</version>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>mysql</groupId>
            <artifactId>mysql-connector-java</artifactId>
            <version>5.1.47</version>
        </dependency>
    </dependencies>

    <build>
        <plugins>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-assembly-plugin</artifactId>
                <version>2.5.5</version>
                <configuration>
                    <archive>
                        <manifestFile>src/main/resources/META-INF/MANIFEST.MF</manifestFile>
                    </archive>
                    <descriptorRefs>
                        <descriptorRef>jar-with-dependencies</descriptorRef>
                    </descriptorRefs>
                </configuration>
            </plugin>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-compiler-plugin</artifactId>
                <version>2.3.1</version>
                <configuration>
                    <source>1.8</source>
                    <target>1.8</target>
                    <encoding>utf8</encoding>
                </configuration>
            </plugin>
        </plugins>
    </build>
</project>

package com.tameti.bytecode;

import lombok.Data;
import lombok.ToString;

@Data
@ToString
public class ServletInfo {
    /**
     * 主键
     */
    private String id;

    /**
     * 监控的 SERVLET 所属系统信息
     */
    private String system;

    /**
     * 请求会话信息
     */
    private String session;

    /**
     * 所属父亲会话
     */
    private String parentSession;

    /**
     * 请求的资源路径
     */
    private String url;

    /**
     * 请求由哪个地址创建的
     */
    private String address;

    /**
     * 请求的方法类型, GET | POST | PUT | DELETE | TRACE | OPTIONS
     */
    private String method;

    /**
     * 请求头的信息
     */
    private String header;

    /**
     * 请求参数的信息
     */
    private String params;

    /**
     * 请求创建的时间
     */
    private long startTime;

    /**
     * 请求总共耗时秒数
     */
    private long userTime;
}

SQL表

CREATE TABLE `servlet_info` (
  `id` varchar(50) NOT NULL,
  `system` varchar(30) NOT NULL COMMENT '监控的 SERVLET 所属系统信息',
  `session` varchar(50) NOT NULL COMMENT '请求会话信息',
  `parent_session` varchar(30) NOT NULL COMMENT '所属父会话信息, 因为可能存在 A 系统调用 B 系统的情况, 所以这里使用 parent_session 来记录多个系统之前相互调用的情况',
  `url` varchar(200) NOT NULL COMMENT '请求的资源路径',
  `address` varchar(50) NOT NULL COMMENT '请求方的地址信息',
  `method` varchar(10) NOT NULL COMMENT '请求类型, GET|POST|PUT|DELETE|TRACE|OPTIONS',
  `header` varchar(3000) DEFAULT NULL COMMENT '请求头信息',
  `params` mediumtext COMMENT '请求携带的参数信息',
  `startTime` mediumtext COMMENT '请求到达时间',
  `userTime` mediumtext COMMENT '处理请求消耗的时间, 单位ms',
  PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8

package com.tameti.bytecode.utils;

import com.tameti.bytecode.ServletInfo;

import java.sql.Connection;
import java.sql.PreparedStatement;
import java.sql.SQLException;

public class DB {
    private Connection connection;

    public DB(Connection connection) {
        this.connection = connection;
    }

    public int insertServletInfo(ServletInfo info) {
        try {
            System.out.println(info.toString());
            PreparedStatement ps = connection.prepareStatement("INSERT INTO `servlet_info`(id, system, `session`, parent_session, url, address, method, header, params, startTime, userTime) VALUES(?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?);");
            ps.setString(1, info.getId());
            ps.setString(2, info.getSystem());
            ps.setString(3, info.getSession());
            ps.setString(4, info.getParentSession());
            ps.setString(5, info.getUrl());
            ps.setString(6, info.getAddress());
            ps.setString(7, info.getMethod());
            ps.setString(8, info.getHeader());
            ps.setString(9, info.getParams());
            ps.setLong(10, info.getStartTime());
            ps.setLong(11, info.getUserTime());
            return ps.executeUpdate();
        } catch (SQLException e) {
            return -1;
        }
    }
}

定义切面入口

package com.tameti.bytecode;

import com.tameti.bytecode.utils.DB;
import javassist.*;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.lang.instrument.ClassFileTransformer;
import java.lang.instrument.IllegalClassFormatException;
import java.lang.instrument.Instrumentation;
import java.security.ProtectionDomain;
import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.SQLException;
import java.text.SimpleDateFormat;
import java.util.Enumeration;
import java.util.UUID;

/**
 * 字节码插桩: 基于 javassist.
 */
public class AgentApplication implements ClassFileTransformer {
    public static final ClassPool pool = ClassPool.getDefault();

    static {
        try {
            Class.forName("com.mysql.jdbc.Driver");
        } catch (ClassNotFoundException e) {
            e.printStackTrace();
        }
    }

    public static ServletInfo begin(HttpServletRequest request, HttpServletResponse response) {
        ServletInfo servletInfo = new ServletInfo();
        servletInfo.setId(UUID.randomUUID().toString());
        servletInfo.setSystem("WebServer");
        servletInfo.setSession(request.getSession().getId());
        Object proxy_parent_session = request.getAttribute("_proxy_parent_session");
        servletInfo.setParentSession(proxy_parent_session == null ? "" : proxy_parent_session.toString());
        servletInfo.setUrl(request.getRequestURI());
        servletInfo.setAddress(request.getRemoteAddr());
        servletInfo.setMethod(request.getMethod());


        StringBuilder sb = new StringBuilder("{");

        // 请求头信息
        Enumeration<String> headerNames = request.getHeaderNames();
        while (headerNames.hasMoreElements()) {
            String h = headerNames.nextElement();
            String v = request.getHeader(h);
            sb.append("\"").append(h).append("\":\"").append(v).append("\",");
        }
        if (sb.length() > 1) {
            sb = new StringBuilder(sb.substring(0, sb.length() - 1));
        }
        sb.append("}");

        servletInfo.setHeader(sb.toString());

        // 请求携带参数
        sb = new StringBuilder("{");

        Enumeration<String> parameterNames = request.getParameterNames();
        while (parameterNames.hasMoreElements()) {
            String p = parameterNames.nextElement();
            String v = request.getParameter(p);
            sb.append("\"").append(p).append("\":\"").append(v).append("\",");
        }
        if (sb.length() > 1) {
            sb = new StringBuilder(sb.substring(0, sb.length() - 1));
        }
        sb.append("}");

        servletInfo.setParams(sb.toString());
        long startTime = System.currentTimeMillis();
        servletInfo.setStartTime(startTime);
        return servletInfo;
    }

    public static void end(ServletInfo info) {
        info.setUserTime(System.currentTimeMillis() - info.getStartTime());
        new Thread(() -> {
            try {
                Connection connection = DriverManager.getConnection("jdbc:mysql://localhost:3306/db1", "root", "123456");
                DB db = new DB(connection);
                db.insertServletInfo(info);
            } catch (SQLException e) {
                e.printStackTrace();
            }
        }).start();
    }

    // java-agent 入口方法
    public static void premain(String arg, Instrumentation instrumentation) {
        instrumentation.addTransformer(new AgentApplication());
    }

    @Override
    public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined, ProtectionDomain protectionDomain, byte[] classfileBuffer) throws IllegalClassFormatException {
        String finalClassName = className.replace("/", ".");
        try {
            // 通过监控 HttpServlet 的 service(HttpServletRequest, HttpServletResponse) 来完成请求信息统计
            if (finalClassName.equals("javax.servlet.http.HttpServlet")) {
                // 将当前的 classpath 加入到 classloader 中
                pool.insertClassPath(new LoaderClassPath(loader));
                CtClass servletClass = pool.getCtClass(finalClassName);
                CtClass[] params = new CtClass[]{
                        pool.get("javax.servlet.http.HttpServletRequest"),
                        pool.get("javax.servlet.http.HttpServletResponse")
                };

                CtMethod service = servletClass.getDeclaredMethod("service", params);
                // 基于原来的方法创建出一个 service$agent 方法
                CtMethod service$agent = CtNewMethod.copy(service, "service$agent", servletClass, null);
                // 在原来的类中把这个方法添加进去
                servletClass.addMethod(service$agent);
                // 修改原来的方法里面的执行逻辑, 先执行 begin 方法返回一个 ServletInfo
                // 然后执行完原来的 service 方法后, 继续执行 end 方法. end 方法接收一个 ServletInfo 对象, 执行完毕后整个代码结束
                service.setBody("{\n" +
                        "\tcom.tameti.bytecode.ServletInfo  info = com.tameti.bytecode.AgentApplication.begin($$);\n" +
                        "\tservice$agent($$);\n" +
                        "\tcom.tameti.bytecode.AgentApplication.end(info);\n" +
                        "}");
                // 返回修改后的类字节码
                return servletClass.toBytecode();
            }

        } catch (Exception e) {
            System.err.println(e.getMessage());
        }
        return new byte[0];
    }

}

将这个依赖编译打成 jar 包, 然后监控 SpringBoot 应用. 现在监控几个请求后看看数据库里面的结果

id	system	session	parent_session	url	address	method	header	params	startTime	userTime
09f01b1f-807a-4735-bb64-46789a39f77f	WebServer	631AD49115C393144713C2176E1422F8		/dev	0:0:0:0:0:0:0:1	GET	{"host":"localhost:8080","connection":"keep-alive","cache-control":"max-age=0","sec-ch-ua":"" Not;A Brand";v="99", "Google Chrome";v="91", "Chromium";v="91"","sec-ch-ua-mobile":"?0","upgrade-insecure-requests":"1","user-agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.124 Safari/537.36","accept":"text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9","sec-fetch-site":"none","sec-fetch-mode":"navigate","sec-fetch-user":"?1","sec-fetch-dest":"document","accept-encoding":"gzip, deflate, br","accept-language":"zh-CN,zh;q=0.9","cookie":"Idea-39b9dd95=bd61abab-a6f5-4866-aab2-901cf43d0220; JSESSIONID=631AD49115C393144713C2176E1422F8"}	{}	1626340619369	5
21b81527-d68a-41d1-a66b-0a87b2433bae	WebServer	1C095BC06685AE1E5110251FA0BD6544		/api/area/files	0:0:0:0:0:0:0:1	GET	{"host":"localhost:8080","connection":"keep-alive","sec-ch-ua":"" Not;A Brand";v="99", "Google Chrome";v="91", "Chromium";v="91"","sec-ch-ua-mobile":"?0","user-agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.124 Safari/537.36","accept":"*/*","sec-fetch-site":"same-origin","sec-fetch-mode":"cors","sec-fetch-dest":"empty","referer":"http://localhost:8080/dev","accept-encoding":"gzip, deflate, br","accept-language":"zh-CN,zh;q=0.9","cookie":"Idea-39b9dd95=bd61abab-a6f5-4866-aab2-901cf43d0220; JSESSIONID=1C095BC06685AE1E5110251FA0BD6544"}	{"rand":"0.9369115749292933","key":"??????"}	1626341115163	365
24e7d302-b192-4515-a3dc-a759d307daa0	WebServer	631AD49115C393144713C2176E1422F8		/error	0:0:0:0:0:0:0:1	GET	{"host":"localhost:8080","connection":"keep-alive","sec-ch-ua":"" Not;A Brand";v="99", "Google Chrome";v="91", "Chromium";v="91"","sec-ch-ua-mobile":"?0","user-agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.124 Safari/537.36","accept":"*/*","sec-fetch-site":"same-origin","sec-fetch-mode":"cors","sec-fetch-dest":"empty","referer":"http://localhost:8080/dev","accept-encoding":"gzip, deflate, br","accept-language":"zh-CN,zh;q=0.9","cookie":"Idea-39b9dd95=bd61abab-a6f5-4866-aab2-901cf43d0220; JSESSIONID=631AD49115C393144713C2176E1422F8"}	{"rand":"0.17328345138016554","key":"undefined","dirname":"files => {                     city.areas[areaIndex].files = files;                     city.areas[areaIndex].loading = false;                 }"}	1626340701547	3
2a555e0c-f8ac-45ff-8646-6362fa29c721	WebServer	631AD49115C393144713C2176E1422F8		/	0:0:0:0:0:0:0:1	GET	{"host":"localhost:8080","connection":"keep-alive","sec-ch-ua":"" Not;A Brand";v="99", "Google Chrome";v="91", "Chromium";v="91"","sec-ch-ua-mobile":"?0","upgrade-insecure-requests":"1","user-agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.124 Safari/537.36","accept":"text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9","sec-fetch-site":"none","sec-fetch-mode":"navigate","sec-fetch-user":"?1","sec-fetch-dest":"document","accept-encoding":"gzip, deflate, br","accept-language":"zh-CN,zh;q=0.9","cookie":"Idea-39b9dd95=bd61abab-a6f5-4866-aab2-901cf43d0220"}	{}	1626340593552	174

现在监控的请求数据就入库了. 我们就可以根据请求时间和 SESSION_ID 来计算出这个系统中一天有多少个请求, 一天存在多少个用户, 每个小时的请求密度, 以及针对每个请求路径的访问次数. 以及系统的处理效率之类的信息

监控 JDBC 

这里监控 JDBC 比监控 HttpServlet 复杂多了,  JDBC 的执行流程其实还是挺简单的:

1. 获取驱动对象

Class.forName("com.mysql.cj.jdbc.Driver");

2. 创建连接

Connection connection = DriverManager.getConnection("jdbc:mysql://localhost:8080/db1", "root", "123456");

3. 创建预处理对象

PrepareStatement ps = connection.prepareStatement("SELECT * FROM servlet_info WHERE `session` = ?");

ps.setString(1, "DHAWHBGAWVGAWQD134");

4. 执行 SQL 并获取结果

ResultSet rs = ps.executeQuery();

现在我们需要对整个流程进行一个动态代理, 从而得到执行的 SQL 语句, 以及每一条的 SQL 语句执行耗时. 先看看大概的效果是啥样的

Class.forName("com.mysql.cj.jdbc.Driver");
Connection connection = DriverManager.getConnection("jdbc:mysql://127.0.0.1:3306/db1", "root", "123456");


PreparedStatement ps = connection.prepareStatement("SELECT * FROM servlet_info");
// 拿到执行的 SQL
String sql = ((ClientPreparedStatement) ps).getPreparedSql();

// SQL 执行开始的时间
long startTime = System.currentTimeMillis();

ResultSet resultSet = ps.executeQuery();

// SQL 执行结束的时间
long endTime = System.currentTimeMillis();
// 这条 SQL 的总共耗时
long useTime = endTime - startTime;

我们首先需要需要代理 DriverManager.getConnection, 让它返回的 java.sql.Connection 是我们自己定义的 Connection, 然后代理 Connection 的 prepareStatement 方法, 通过代理这个方法从而拿到执行的 sql 语句, 接着我们还要代理 setString, setObject... 这些参数注入方法, 这样我们才能拿到方法调用后的具体参数. 接下来看代码演示:

package com.tameti.bytecode;

import java.lang.reflect.Proxy;
import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.PreparedStatement;
import java.util.HashMap;
import java.util.Map;

public class AgentApplication {
    private static ClassLoader loader = AgentApplication.class.getClassLoader();
    // 存储我们采集的参数的参数选项和参数值的容器
    private static final Map<String, Object> map = new HashMap<>();

    public static void main(String[] args) throws Exception {
        Class.forName("com.mysql.jdbc.Driver");
        Connection connection = DriverManager.getConnection("jdbc:mysql://127.0.0.1:3306/db8", "root", "123456");
        // 对 connection 对象进行一个动态代理, 从而返回特殊的 PrepareStatement 对象
        connection = proxyConnection(connection);
        
        // 这里的几个方法已经被我给静态代理
        PreparedStatement ps = connection.prepareStatement("SELECT * FROM servlet_info WHERE `session`=? AND `url` != ?");
        ps.setString(1, "631AD49115C393144713C2176E1422F8");
        ps.setString(2, "/favicon.ico");
        // 执行 sql 语句
        ps.executeQuery();


        long startTime = (long) map.get("startTime");
        long endTime = (long) map.get("endTime");
        map.put("userTime", endTime - startTime);
        map.forEach((key, value) -> System.out.println("key:" + key + ", value:" + value));
    }
    
    /**
     * 对 Connection 对象进行一个动态代理
     */
    private static Connection proxyConnection(Connection conn) {
        return (Connection) Proxy.newProxyInstance(loader, new Class[]{Connection.class}, (proxy, method, args) -> {
            // 代理这个 prepareStatement 方法
            boolean isTarget = method.getName().equals("prepareStatement");

            Object result = null;
            try {
                if (isTarget) {
                    // 拿到 jdbcUrl 的值
                    map.put("jdbcUrl", conn.getMetaData().getURL());
                    // 拿到 PrepareStatement 中的 sql 对象
                    map.put("prepareSql", args[0]);
                }
                // 继续执行原来方法的结果
                result = method.invoke(conn, args);
                if (isTarget && result instanceof PreparedStatement) {
                    // 对得到的 PrepareStatement 进行一层代理
                    result = proxyPrepareStatement((PreparedStatement) result);
                }
            } catch (Throwable e) {
                throw e;
            }
            return result;
        });
    }

    private static PreparedStatement proxyPrepareStatement(PreparedStatement ps) {
        // 返回我自己定义的 PrepareStatement 对象
        return new ProxyPreparedStatement(ps, map);
    }
}

package com.tameti.bytecode;

import java.io.InputStream;
import java.io.Reader;
import java.math.BigDecimal;
import java.net.URL;
import java.sql.*;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Calendar;
import java.util.Map;

public class ProxyPreparedStatement implements PreparedStatement {
    private PreparedStatement ps;
    private Map<String, Object> map;

    public ProxyPreparedStatement(PreparedStatement ps, Map<String, Object> map) {
        this.ps = ps;
        this.map = map;
        try {
            map.put("parameters", new ArrayList<String>(ps.getParameterMetaData().getParameterCount()));
        } catch (SQLException e) {
            e.printStackTrace();
        }
    }

    private void add(int index, String typeClassName, Object value) {
        ArrayList<String> parameters = (ArrayList<String>) map.get("parameters");
        parameters.add(index - 1, typeClassName + ":" + value);
    }

    private void getFinallySql() {
        String sql = ps.toString();
        if (sql.contains(":")) {
            sql = sql.substring(sql.indexOf(":"));
            map.put("finallySql", sql);
        }
    }

    @Override
    public ResultSet executeQuery() throws SQLException {
        map.put("sqlType", "query");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        ResultSet rs = ps.executeQuery();
        map.put("endTime", System.currentTimeMillis());
        map.put("row", rs.getRow());
        return rs;
    }

    @Override
    public int executeUpdate() throws SQLException {
        map.put("sqlType", "update");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        int result = ps.executeUpdate();
        map.put("endTime", System.currentTimeMillis());
        map.put("row", result);
        return result;
    }

    @Override
    public void setNull(int parameterIndex, int sqlType) throws SQLException {
        ps.setNull(parameterIndex, sqlType);
    }

    @Override
    public void setBoolean(int parameterIndex, boolean x) throws SQLException {
        add(parameterIndex, "java.lang.Boolean", x);
        ps.setBoolean(parameterIndex, x);
    }

    @Override
    public void setByte(int parameterIndex, byte x) throws SQLException {
        add(parameterIndex, "java.lang.Byte", x);
        ps.setByte(parameterIndex, x);
    }

    @Override
    public void setShort(int parameterIndex, short x) throws SQLException {
        add(parameterIndex, "java.lang.Short", x);
        ps.setShort(parameterIndex, x);
    }

    @Override
    public void setInt(int parameterIndex, int x) throws SQLException {
        add(parameterIndex, "java.lang.Integer", x);
        ps.setInt(parameterIndex, x);
    }

    @Override
    public void setLong(int parameterIndex, long x) throws SQLException {
        add(parameterIndex, "java.lang.Long", x);
        ps.setLong(parameterIndex, x);
    }

    @Override
    public void setFloat(int parameterIndex, float x) throws SQLException {
        add(parameterIndex, "java.lang.Float", x);
        ps.setFloat(parameterIndex, x);
    }

    @Override
    public void setDouble(int parameterIndex, double x) throws SQLException {
        add(parameterIndex, "java.lang.Double", x);
        ps.setDouble(parameterIndex, x);
    }

    @Override
    public void setBigDecimal(int parameterIndex, BigDecimal x) throws SQLException {
        add(parameterIndex, "java.math.BigDecimal", x);
        ps.setBigDecimal(parameterIndex, x);
    }

    @Override
    public void setString(int parameterIndex, String x) throws SQLException {
        add(parameterIndex, "java.lang.String", x);
        ps.setString(parameterIndex, x);
    }

    @Override
    public void setBytes(int parameterIndex, byte[] x) throws SQLException {
        add(parameterIndex, "byte[]", Arrays.toString(x));
        ps.setBytes(parameterIndex, x);
    }

    @Override
    public void setDate(int parameterIndex, Date x) throws SQLException {
        add(parameterIndex, "java.util.Date", x.getTime());
        ps.setDate(parameterIndex, x);
    }

    @Override
    public void setTime(int parameterIndex, Time x) throws SQLException {
        add(parameterIndex, "java.sql.Time", x.getTime());
        ps.setTime(parameterIndex, x);
    }

    @Override
    public void setTimestamp(int parameterIndex, Timestamp x) throws SQLException {
        add(parameterIndex, "java.sql.Timestamp", x.getTime());
        ps.setTimestamp(parameterIndex, x);
    }

    @Override
    public void setAsciiStream(int parameterIndex, InputStream x, int length) throws SQLException {
        add(parameterIndex, "java.io.InputStream", x.toString());
        ps.setAsciiStream(parameterIndex, x, length);
    }

    @Override
    public void setUnicodeStream(int parameterIndex, InputStream x, int length) throws SQLException {
        add(parameterIndex, "java.io.InputStream", x.toString());
        ps.setUnicodeStream(parameterIndex, x, length);
    }

    @Override
    public void setBinaryStream(int parameterIndex, InputStream x, int length) throws SQLException {
        add(parameterIndex, "java.io.InputStream", x.toString());
        ps.setBinaryStream(parameterIndex, x, length);
    }

    @Override
    public void clearParameters() throws SQLException {
        ArrayList<String> parameters = (ArrayList<String>) map.get("parameters");
        parameters.clear();
        ps.clearParameters();
    }

    @Override
    public void setObject(int parameterIndex, Object x, int targetSqlType) throws SQLException {
        add(parameterIndex, "java.lang.Object", x.toString());
        ps.setObject(parameterIndex, x, targetSqlType);
    }

    @Override
    public void setObject(int parameterIndex, Object x) throws SQLException {
        add(parameterIndex, "java.lang.Object", x.toString());
        ps.setObject(parameterIndex, x);
    }

    @Override
    public boolean execute() throws SQLException {
        map.put("sqlType", "execute");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        boolean result = ps.execute();
        map.put("endTime", System.currentTimeMillis());
        map.put("status", result);
        return result;
    }

    @Override
    public void addBatch() throws SQLException {
        ps.addBatch();
    }

    @Override
    public void setCharacterStream(int parameterIndex, Reader reader, int length) throws SQLException {
        add(parameterIndex, "java.io.Reader", reader.toString());
        ps.setCharacterStream(parameterIndex, reader, length);
    }

    @Override
    public void setRef(int parameterIndex, Ref x) throws SQLException {
        add(parameterIndex, "java.sql.Ref", x.getObject().toString());
        ps.setRef(parameterIndex, x);
    }

    @Override
    public void setBlob(int parameterIndex, Blob x) throws SQLException {
        add(parameterIndex, "java.sql.Blob", new String(x.getBytes(0, (int) x.length())));
        ps.setBlob(parameterIndex, x);
    }

    @Override
    public void setClob(int parameterIndex, Clob x) throws SQLException {
        add(parameterIndex, "java.sql.Clob", x.getSubString(0, (int) x.length()));
        ps.setClob(parameterIndex, x);
    }

    @Override
    public void setArray(int parameterIndex, Array x) throws SQLException {
        add(parameterIndex, "java.sql.Array", x.getArray().toString());
        ps.setArray(parameterIndex, x);
    }

    @Override
    public ResultSetMetaData getMetaData() throws SQLException {
        return ps.getMetaData();
    }

    @Override
    public void setDate(int parameterIndex, Date x, Calendar cal) throws SQLException {
        add(parameterIndex, "java.sql.Date", x.getTime());
        ps.setDate(parameterIndex, x, cal);
    }

    @Override
    public void setTime(int parameterIndex, Time x, Calendar cal) throws SQLException {
        add(parameterIndex, "java.sql.Time", x.getTime());
        ps.setTime(parameterIndex, x, cal);
    }

    @Override
    public void setTimestamp(int parameterIndex, Timestamp x, Calendar cal) throws SQLException {
        add(parameterIndex, "java.sql.Timestamp", x.getTime());
        ps.setTimestamp(parameterIndex, x, cal);
    }

    @Override
    public void setNull(int parameterIndex, int sqlType, String typeName) throws SQLException {
        ps.setNull(parameterIndex, sqlType, typeName);
    }

    @Override
    public void setURL(int parameterIndex, URL x) throws SQLException {
        add(parameterIndex, "java.net.URL", x.toString());
        ps.setURL(parameterIndex, x);
    }

    @Override
    public ParameterMetaData getParameterMetaData() throws SQLException {
        return ps.getParameterMetaData();
    }

    @Override
    public void setRowId(int parameterIndex, RowId x) throws SQLException {
        add(parameterIndex, "java.sql.RowId", new String(x.getBytes()));
        ps.setRowId(parameterIndex, x);
    }

    @Override
    public void setNString(int parameterIndex, String value) throws SQLException {
        add(parameterIndex, "java.lang.String", value);
        ps.setNString(parameterIndex, value);
    }

    @Override
    public void setNCharacterStream(int parameterIndex, Reader value, long length) throws SQLException {
        add(parameterIndex, "java.io.Reader", value.toString());
        ps.setNCharacterStream(parameterIndex, value, length);
    }

    @Override
    public void setNClob(int parameterIndex, NClob value) throws SQLException {
        add(parameterIndex, "java.sql.NClob", value.getSubString(0, (int) value.length()));
        ps.setNClob(parameterIndex, value);
    }

    @Override
    public void setClob(int parameterIndex, Reader reader, long length) throws SQLException {
        add(parameterIndex, "java.io.Reader", reader.toString());
        ps.setClob(parameterIndex, reader, length);
    }

    @Override
    public void setBlob(int parameterIndex, InputStream inputStream, long length) throws SQLException {
        add(parameterIndex, "java.io.InputStream", inputStream.toString());
        ps.setBlob(parameterIndex, inputStream, length);
    }

    @Override
    public void setNClob(int parameterIndex, Reader reader, long length) throws SQLException {
        add(parameterIndex, "java.io.Reader", reader.toString());
        ps.setNClob(parameterIndex, reader, length);
    }

    @Override
    public void setSQLXML(int parameterIndex, SQLXML xmlObject) throws SQLException {
        add(parameterIndex, "java.sql.SQLXML", xmlObject);
        ps.setSQLXML(parameterIndex, xmlObject);
    }

    @Override
    public void setObject(int parameterIndex, Object x, int targetSqlType, int scaleOrLength) throws SQLException {
        add(parameterIndex, "java.lang.Object", x);
        ps.setObject(parameterIndex, x, targetSqlType, scaleOrLength);
    }

    @Override
    public void setAsciiStream(int parameterIndex, InputStream x, long length) throws SQLException {
        add(parameterIndex, "java.io.InputStream", x);
        ps.setAsciiStream(parameterIndex, x, length);
    }

    @Override
    public void setBinaryStream(int parameterIndex, InputStream x, long length) throws SQLException {
        add(parameterIndex, "java.io.InputStream", x);
        ps.setBinaryStream(parameterIndex, x, length);
    }

    @Override
    public void setCharacterStream(int parameterIndex, Reader reader, long length) throws SQLException {
        add(parameterIndex, "java.io.Reader", reader);
        ps.setCharacterStream(parameterIndex, reader, length);
    }

    @Override
    public void setAsciiStream(int parameterIndex, InputStream x) throws SQLException {
        add(parameterIndex, "java.io.InputStream", x);
        ps.setAsciiStream(parameterIndex, x);
    }

    @Override
    public void setBinaryStream(int parameterIndex, InputStream x) throws SQLException {
        add(parameterIndex, "java.io.InputStream", x);
        ps.setBinaryStream(parameterIndex, x);
    }

    @Override
    public void setCharacterStream(int parameterIndex, Reader reader) throws SQLException {
        add(parameterIndex, "java.io.Reader", reader);
        ps.setCharacterStream(parameterIndex, reader);
    }

    @Override
    public void setNCharacterStream(int parameterIndex, Reader value) throws SQLException {
        add(parameterIndex, "java.io.Reader", value);
        ps.setNCharacterStream(parameterIndex, value);
    }

    @Override
    public void setClob(int parameterIndex, Reader reader) throws SQLException {
        add(parameterIndex, "java.io.Reader", reader);
        ps.setClob(parameterIndex, reader);
    }

    @Override
    public void setBlob(int parameterIndex, InputStream inputStream) throws SQLException {
        add(parameterIndex, "java.io.InputStream", inputStream.toString());
        ps.setBlob(parameterIndex, inputStream);
    }

    @Override
    public void setNClob(int parameterIndex, Reader reader) throws SQLException {
        add(parameterIndex, "java.io.Reader", reader.toString());
        ps.setNClob(parameterIndex, reader);
    }

    @Override
    public ResultSet executeQuery(String sql) throws SQLException {
        map.put("sqlType", "query");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        ResultSet result = ps.executeQuery(sql);
        map.put("endTime", System.currentTimeMillis());
        map.put("row", result.getRow());
        return result;
    }

    @Override
    public int executeUpdate(String sql) throws SQLException {
        map.put("sqlType", "update");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        int result = ps.executeUpdate(sql);
        map.put("endTime", System.currentTimeMillis());
        map.put("row", result);
        return result;
    }

    @Override
    public void close() throws SQLException {
        ps.close();
    }

    @Override
    public int getMaxFieldSize() throws SQLException {
        return ps.getMaxFieldSize();
    }

    @Override
    public void setMaxFieldSize(int max) throws SQLException {
        ps.setMaxFieldSize(max);
    }

    @Override
    public int getMaxRows() throws SQLException {
        return ps.getMaxRows();
    }

    @Override
    public void setMaxRows(int max) throws SQLException {
        ps.setMaxRows(max);
    }

    @Override
    public void setEscapeProcessing(boolean enable) throws SQLException {
        ps.setEscapeProcessing(enable);
    }

    @Override
    public int getQueryTimeout() throws SQLException {
        return ps.getQueryTimeout();
    }

    @Override
    public void setQueryTimeout(int seconds) throws SQLException {
        ps.setQueryTimeout(seconds);
    }

    @Override
    public void cancel() throws SQLException {
        ps.cancel();
    }

    @Override
    public SQLWarning getWarnings() throws SQLException {
        return ps.getWarnings();
    }

    @Override
    public void clearWarnings() throws SQLException {
        ps.clearWarnings();
    }

    @Override
    public void setCursorName(String name) throws SQLException {
        ps.setCursorName(name);
    }

    @Override
    public boolean execute(String sql) throws SQLException {
        map.put("sqlType", "execute");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        boolean result = ps.execute(sql);
        map.put("endTime", System.currentTimeMillis());
        map.put("status", result);
        return result;
    }

    @Override
    public ResultSet getResultSet() throws SQLException {
        return ps.getResultSet();
    }

    @Override
    public int getUpdateCount() throws SQLException {
        return ps.getUpdateCount();
    }

    @Override
    public boolean getMoreResults() throws SQLException {
        return ps.getMoreResults();
    }

    @Override
    public void setFetchDirection(int direction) throws SQLException {
        ps.setFetchDirection(direction);
    }

    @Override
    public int getFetchDirection() throws SQLException {
        return ps.getFetchDirection();
    }

    @Override
    public void setFetchSize(int rows) throws SQLException {
        ps.setFetchSize(rows);
    }

    @Override
    public int getFetchSize() throws SQLException {
        return ps.getFetchSize();
    }

    @Override
    public int getResultSetConcurrency() throws SQLException {
        return ps.getResultSetConcurrency();
    }

    @Override
    public int getResultSetType() throws SQLException {
        return ps.getResultSetType();
    }

    @Override
    public void addBatch(String sql) throws SQLException {
        ps.addBatch(sql);
    }

    @Override
    public void clearBatch() throws SQLException {
        ps.clearBatch();
    }

    @Override
    public int[] executeBatch() throws SQLException {
        map.put("sqlType", "batch");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        int[] result = ps.executeBatch();
        map.put("endTime", System.currentTimeMillis());
        map.put("row", Arrays.toString(result));
        return result;
    }

    @Override
    public Connection getConnection() throws SQLException {
        return ps.getConnection();
    }

    @Override
    public boolean getMoreResults(int current) throws SQLException {
        return ps.getMoreResults(current);
    }

    @Override
    public ResultSet getGeneratedKeys() throws SQLException {
        return ps.getGeneratedKeys();
    }

    @Override
    public int executeUpdate(String sql, int autoGeneratedKeys) throws SQLException {
        map.put("sqlType", "execute");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        int result = ps.executeUpdate(sql, autoGeneratedKeys);
        map.put("endTime", System.currentTimeMillis());
        map.put("row", result);
        return result;
    }

    @Override
    public int executeUpdate(String sql, int[] columnIndexes) throws SQLException {
        map.put("sqlType", "execute");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        int result = ps.executeUpdate(sql, columnIndexes);
        map.put("endTime", System.currentTimeMillis());
        map.put("row", result);
        return result;
    }

    @Override
    public int executeUpdate(String sql, String[] columnNames) throws SQLException {
        map.put("sqlType", "execute");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        int result = ps.executeUpdate(sql, columnNames);
        map.put("endTime", System.currentTimeMillis());
        map.put("row", result);
        return result;
    }

    @Override
    public boolean execute(String sql, int autoGeneratedKeys) throws SQLException {
        map.put("sqlType", "execute");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        boolean result = ps.execute(sql, autoGeneratedKeys);
        map.put("endTime", System.currentTimeMillis());
        map.put("status", result);
        return result;
    }

    @Override
    public boolean execute(String sql, int[] columnIndexes) throws SQLException {
        map.put("sqlType", "execute");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        boolean result = ps.execute(sql, columnIndexes);
        map.put("endTime", System.currentTimeMillis());
        map.put("status", result);
        return result;
    }

    @Override
    public boolean execute(String sql, String[] columnNames) throws SQLException {
        map.put("sqlType", "execute");
        map.put("startTime", System.currentTimeMillis());
        getFinallySql();
        boolean result = ps.execute(sql, columnNames);
        map.put("endTime", System.currentTimeMillis());
        map.put("status", result);
        return result;
    }

    @Override
    public int getResultSetHoldability() throws SQLException {
        return ps.getResultSetHoldability();
    }

    @Override
    public boolean isClosed() throws SQLException {
        return ps.isClosed();
    }

    @Override
    public void setPoolable(boolean poolable) throws SQLException {
        ps.setPoolable(poolable);
    }

    @Override
    public boolean isPoolable() throws SQLException {
        return ps.isPoolable();
    }

    @Override
    public void closeOnCompletion() throws SQLException {
        ps.closeOnCompletion();
    }

    @Override
    public boolean isCloseOnCompletion() throws SQLException {
        return ps.isCloseOnCompletion();
    }

    @Override
    public <T> T unwrap(Class<T> iface) throws SQLException {
        return ps.unwrap(iface);
    }

    @Override
    public boolean isWrapperFor(Class<?> iface) throws SQLException {
        return ps.isWrapperFor(iface);
    }
}

现在编译运行, 看看拦截到的结果:

# 编译前的 SQL
key:prepareSql, value:SELECT * FROM servlet_info WHERE `session`=? AND `url` != ?
# 这条 SQL 的执行类型, query | execute | update
key:sqlType, value:query
# 这条 SQL 执行耗时, 单位 ms
key:userTime, value:15
# 这条 SQL 使用的 jdbc 连接
key:jdbcUrl, value:jdbc:mysql://127.0.0.1:3306/db8
# 这条 SQL 执行时的时间
key:startTime, value:1626675721869
# 这条 SQL 执行完成的时间
key:endTime, value:1626675721884
# 查询结果条数, 这里有点问题
key:row, value:0
# 最终编译生成的 SQL
key:finallySql, value:: SELECT * FROM servlet_info WHERE `session`='631AD49115C393144713C2176E1422F8' AND `url` != '/favicon.ico'
# 携带的参数数组
key:parameters, value:[java.lang.String:631AD49115C393144713C2176E1422F8, java.lang.String:/favicon.ico]

 记然可以拿到最终编译生成的 SQL, 那我们也可以在这条 SQL 的前面添加一个 EXPLAIN 从而分析这条 SQL 的执行计划. 关于这个 JDBC 整合 JavaAgent 我暂时不写先, 后面再说吧. 原理就是上面这样的

调用链

按照上面的逻辑, 只是简单的监控这种 Servlet 请求, 那还是太简单了. 我们要的是知道整个系统的运行流程. 从而方便我们监控这个系统. 当出现一个异常的时候, 系统会在日志中打印一系列的异常堆栈. 开发者可以根据异常堆栈来找到出错的地方, 然后修改代码来解决这个异常. 我们的调用链系统参考了这种原理. 当用户发送一个请求过来的时候, 我们会记录请求的执行轨迹.

这个就是大名鼎鼎的 google 的 drapper 论文的请求流程图, 当业务程序代码在线上运行时，实例A、实例B、实例C，他们直接可能从上到下依次调用，为了能很好的监控程序的调用链路，我们需要对调用链路进行追踪监控。虽然本篇文章不会演示多系统之间的 RPC 调用或 HTTP 调用, 但是针对单系统的请求路径记录, 请求信息的记录还是有一定的学习价值的.

首先, 我们插桩的入口还是在 HttpServlet， 利用 ThreadLocal 来记录方法的执行轨迹. 每一个方法执行的时候都会绑定存在一个 span 和它的父亲 span, 从而得到整条方法的执行轨迹

首先, 我们简单编写一个创建和获取 span 的类和方法

package org.codetool;

public class TrackContext {
    private static final ThreadLocal<Integer> trackLocal = new ThreadLocal<>();

    public static void clear() {
        trackLocal.remove();
    }

    public static Integer getLinkId() {
        return trackLocal.get();
    }

    public static void setLinkId(Integer linkId) {
        trackLocal.set(linkId);
    }
}

package org.codetool;

import java.util.Stack;

public class TrackManager {
    private static final ThreadLocal<Stack<Integer>> track = new ThreadLocal<>();

    private static Integer createSpan() {
        Stack<Integer> stack = track.get();
        if (stack == null) {
            stack = new Stack<>();
            track.set(stack);
        }
        Integer linkId;
        if (stack.isEmpty()) {
            linkId = TrackContext.getLinkId();
            if (linkId == null) {
                linkId = 0;
                TrackContext.setLinkId(linkId);
            }
        } else {
            linkId = stack.peek() + 1;
            TrackContext.setLinkId(linkId);
        }
        return linkId;
    }

    public static Integer createEntrySpan() {
        Integer span = createSpan();
        Stack<Integer> stack = track.get();
        stack.push(span);
        return span;
    }

    public static Integer getExitSpan() {
        Stack<Integer> stack = track.get();
        if (stack == null || stack.isEmpty()) {
            TrackContext.clear();
            return null;
        }
        return stack.pop();
    }

    public static Integer getCurrentSpan() {
        Stack<Integer> stack = track.get();
        if (stack == null || stack.isEmpty()) {
            return null;
        }
        return stack.peek();
    }

}

模拟一段 WEB 调用流程, 前端发起一次请求, 调用 HelloController 的 hello 方法, 而 hello 方法会调用 HelloService 的 m1 , m2， m3 这 3 个方法, 然后 m3 会调用 m4 方法

package org.codetool;


public class WebApplication {

    public static void main(String[] args) {
        HelloController controller = new HelloController();
        controller.hello();
    }

}

package org.codetool;

import java.util.HashMap;
import java.util.Map;

public class HelloController {

    private HelloService helloService = new HelloService();

    public Map<String, Object> hello() {
        Map<String, Object> map = new HashMap<>();
        int a = helloService.m1();
        int b = helloService.m2();
        helloService.m3(a, b);

        return map;
    }

}

package org.codetool;


public class HelloService {

    public int m1() {
        return 1;
    }

    public int m2() {
        return 2;
    }

    public void m3(int a, int b) {
        m4(a % b);
    }

    private void m4(int i) {
        System.out.println(i);
    }

}

编译运行后, 只会输出一个 1

现在我们需要对整个流程进行一个监控. 现在我们先手动硬编码来看看如何记录这个调用流程.

package org.codetool;


public class WebApplication {

    public static String logLevel(Integer span) {
        if (span == null) {
            return "";
        }

        StringBuilder sb = new StringBuilder();
        for (Integer i = 0; i <= span; i++) {
            sb.append("\t");
        }
        return sb.toString();
    }

    public static void main(String[] args) {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.WebApplication::main(String[] args) 方法开始执行, 开始时间:" + startTime);
        HelloController controller = new HelloController();
        controller.hello();
        System.out.println(logLevel(parentSpan) +"链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.WebApplication::main(String[] args) 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();
    }
}

package org.codetool;

import java.util.HashMap;
import java.util.Map;

import static org.codetool.WebApplication.logLevel;

public class HelloController {

    private HelloService helloService = new HelloService();

    public Map<String, Object> hello() {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) +"链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloController::hello() 方法开始执行, 开始时间:" + startTime);

        Map<String, Object> map = new HashMap<>();
        int a = helloService.m1();
        int b = helloService.m2();
        helloService.m3(a, b);

        System.out.println(logLevel(parentSpan) +"链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloController::hello() 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();

        return map;
    }

}

package org.codetool;

import static org.codetool.WebApplication.logLevel;

public class HelloService {

    public int m1() {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m1() 方法开始执行, 开始时间:" + startTime);

        int res = 1;

        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m1() 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();

        return res;
    }


    public int m2() {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m2() 方法开始执行, 开始时间:" + startTime);


        int res = 2;

        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m2() 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();

        return res;
    }

    public void m3(int a, int b) {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m3(int, int) 方法开始执行, 开始时间:" + startTime);


        m4(a % b);

        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m3(int, int) 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();
    }

    private void m4(int i) {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m4(int) 方法开始执行, 开始时间:" + startTime);


        System.out.println(i);

        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m4(int) 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();
    }

}

编译运行

链路追踪:[null-0] 方法:org.codetool.WebApplication::main(String[] args) 方法开始执行, 开始时间:1626493057122
    链路追踪:[0-1] 方法:org.codetool.HelloController::hello() 方法开始执行, 开始时间:1626493057123
        链路追踪:[1-2] 方法:org.codetool.HelloService::m1() 方法开始执行, 开始时间:1626493057123
        链路追踪:[1-2] 方法:org.codetool.HelloService::m1() 方法执行结束, 执行耗时:0ms
        链路追踪:[1-2] 方法:org.codetool.HelloService::m2() 方法开始执行, 开始时间:1626493057124
        链路追踪:[1-2] 方法:org.codetool.HelloService::m2() 方法执行结束, 执行耗时:0ms
        链路追踪:[1-2] 方法:org.codetool.HelloService::m3(int, int) 方法开始执行, 开始时间:1626493057124
            链路追踪:[2-3] 方法:org.codetool.HelloService::m4(int) 方法开始执行, 开始时间:1626493057124
1
            链路追踪:[2-3] 方法:org.codetool.HelloService::m4(int) 方法执行结束, 执行耗时:0ms
        链路追踪:[1-2] 方法:org.codetool.HelloService::m3(int, int) 方法执行结束, 执行耗时:0ms
    链路追踪:[0-1] 方法:org.codetool.HelloController::hello() 方法执行结束, 执行耗时:1ms
链路追踪:[null-0] 方法:org.codetool.WebApplication::main(String[] args) 方法执行结束, 执行耗时:2ms

这样, 每一个方法执行的时候都存在一个 parentId 和 一个 spanId, 比如上面的 org.codetool.HelloController::hello() 它的 parentId 就是 0, 它的 spanId 就是 1. 也就是说 spanId = 0 的那个方法会调用 org.codetool.HelloController::hello() 这个方法

这样打印出来的结果看上去好像是没有什么问题, 但是实际开发中, 比如一个 SpringBoot 项目中, 里面的方法可能不是在同一个线程中被执行的. 因为存在很多的线程池, 比如 数据库连接池, 消息队列连接池, redis连接池.... 而我们上面的代码是基于 ThreadLocal 实现的, ThreadLocal 只能保证同一个线程共享数据. 不同的线程之间无法共享数据. 现在我们试试多线程下还能正常打印调用顺序吗?

现在看一下运行结果:

链路追踪:[null-0] 方法:org.codetool.WebApplication::main(String[] args) 方法开始执行, 开始时间:1626502387453
    链路追踪:[0-1] 方法:org.codetool.HelloController::hello() 方法开始执行, 开始时间:1626502387455
        链路追踪:[1-2] 方法:org.codetool.HelloService::m1() 方法开始执行, 开始时间:1626502387455
        链路追踪:[1-2] 方法:org.codetool.HelloService::m1() 方法执行结束, 执行耗时:2006ms
        链路追踪:[1-2] 方法:org.codetool.HelloService::m2() 方法开始执行, 开始时间:1626502389461
        链路追踪:[1-2] 方法:org.codetool.HelloService::m2() 方法执行结束, 执行耗时:0ms
    链路追踪:[0-1] 方法:org.codetool.HelloController::hello() 方法执行结束, 执行耗时:2038ms
链路追踪:[null-0] 方法:org.codetool.WebApplication::main(String[] args) 方法执行结束, 执行耗时:2040ms
链路追踪:[null-0] 方法:org.codetool.HelloService::m3(int, int) 方法开始执行, 开始时间:1626502389494
    链路追踪:[0-1] 方法:org.codetool.HelloService::m4(int) 方法开始执行, 开始时间:1626502391502
1
    链路追踪:[0-1] 方法:org.codetool.HelloService::m4(int) 方法执行结束, 执行耗时:0ms
链路追踪:[null-0] 方法:org.codetool.HelloService::m3(int, int) 方法执行结束, 执行耗时:2008ms

这里我们可以看到 m3 和 m4 完全和之前的 链路追踪的记录脱轨了, 因为它们已经不处于同一个线程了. 那现在我们要怎么修改我们的代码, 让不是同一个线程的代码也能记录到同一个执行流程中呢? 其实并不难, 我们只需要在创建子线程时, 将父线程中的值深拷贝一份给子线程. 修改一下代码:

package org.codetool;

import java.util.Stack;

public class TrackManager {
    private static final ThreadLocal<Stack<Integer>> track = new ThreadLocal<>();

    public static Stack<Integer> copyStack() {
        Stack<Integer> integers = track.get();
        Stack<Integer> copyStack = new Stack<>();
        for (Integer integer : integers) {
            copyStack.push(integer);
        }
        return copyStack;
    }

    public static void setStack(Stack<Integer> stack) {
        track.set(stack);
    }

    private static Integer createSpan() {
        Stack<Integer> stack = track.get();
        if (stack == null) {
            stack = new Stack<>();
            track.set(stack);
        }
        Integer linkId;
        if (stack.isEmpty()) {
            linkId = TrackContext.getLinkId();
            if (linkId == null) {
                linkId = 0;
                TrackContext.setLinkId(linkId);
            }
        } else {
            linkId = stack.peek() + 1;
            TrackContext.setLinkId(linkId);
        }
        return linkId;
    }

    public static Integer createEntrySpan() {
        Integer span = createSpan();
        Stack<Integer> stack = track.get();
        stack.push(span);
        return span;
    }

    public static Integer getExitSpan() {
        Stack<Integer> stack = track.get();
        if (stack == null || stack.isEmpty()) {
            TrackContext.clear();
            return null;
        }
        return stack.pop();
    }

    public static Integer getCurrentSpan() {
        Stack<Integer> stack = track.get();
        if (stack == null || stack.isEmpty()) {
            return null;
        }
        return stack.peek();
    }
}

package org.codetool;

import java.util.HashMap;
import java.util.Map;
import java.util.Stack;

import static org.codetool.WebApplication.logLevel;

public class HelloController {

    private HelloService helloService = new HelloService();

    public Map<String, Object> hello() {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) +"链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloController::hello() 方法开始执行, 开始时间:" + startTime);

        Map<String, Object> map = new HashMap<>();
        int a = helloService.m1();
        int b = helloService.m2();
        
        // 取出原来的 stack
        Stack<Integer> stack = TrackManager.copyStack();
        new Thread(() -> {
            // 拷贝一份給子线程
            TrackManager.setStack(stack);
            helloService.m3(a, b);
        }).start();

        System.out.println(logLevel(parentSpan) +"链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloController::hello() 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();

        return map;
    }

}

运行结果

链路追踪:[null-0] 方法:org.codetool.WebApplication::main(String[] args) 方法开始执行, 开始时间:1626677389219
    链路追踪:[0-1] 方法:org.codetool.HelloController::hello() 方法开始执行, 开始时间:1626677389221
        链路追踪:[1-2] 方法:org.codetool.HelloService::m1() 方法开始执行, 开始时间:1626677389221
        链路追踪:[1-2] 方法:org.codetool.HelloService::m1() 方法执行结束, 执行耗时:0ms
        链路追踪:[1-2] 方法:org.codetool.HelloService::m2() 方法开始执行, 开始时间:1626677389221
        链路追踪:[1-2] 方法:org.codetool.HelloService::m2() 方法执行结束, 执行耗时:0ms
    链路追踪:[0-1] 方法:org.codetool.HelloController::hello() 方法执行结束, 执行耗时:46ms
链路追踪:[null-0] 方法:org.codetool.WebApplication::main(String[] args) 方法执行结束, 执行耗时:48ms
        链路追踪:[1-2] 方法:org.codetool.HelloService::m3(int, int) 方法开始执行, 开始时间:1626677389267
            链路追踪:[2-3] 方法:org.codetool.HelloService::m4(int) 方法开始执行, 开始时间:1626677391268
1
            链路追踪:[2-3] 方法:org.codetool.HelloService::m4(int) 方法执行结束, 执行耗时:0ms
        链路追踪:[1-2] 方法:org.codetool.HelloService::m3(int, int) 方法执行结束, 执行耗时:2001ms

这里我们可以看到, 这样还是可以追踪到代码的. 但是这种方法要怎么才能配合 javaagent 使用呢? 我们可以对 Runnable 和 Callable 接口一个代理, 实际开发中好多业务都是用线程池来执行异步任务的. 那这个我们要怎么追踪呢?  关于跨线程传递 ThreadLocal 可以参考这篇博客: https://blog.csdn.net/u013452337/article/details/104521703

接下来试试 InheritableThreadLocal 这个类

package org.codetool;

import java.util.Stack;

public class TrackManager {
    private static final InheritableThreadLocal<Stack<Integer>> track = new InheritableThreadLocal<>();

    private static Integer createSpan() {
        Stack<Integer> stack = track.get();
        if (stack == null) {
            stack = new Stack<>();
            track.set(stack);
        }
        Integer linkId;
        if (stack.isEmpty()) {
            linkId = TrackContext.getLinkId();
            if (linkId == null) {
                linkId = 0;
                TrackContext.setLinkId(linkId);
            }
        } else {
            linkId = stack.peek() + 1;
            TrackContext.setLinkId(linkId);
        }
        return linkId;
    }

    public static Integer createEntrySpan() {
        Integer span = createSpan();
        Stack<Integer> stack = track.get();
        stack.push(span);
        return span;
    }

    public static Integer getExitSpan() {
        Stack<Integer> stack = track.get();
        if (stack == null || stack.isEmpty()) {
            TrackContext.clear();
            return null;
        }
        return stack.pop();
    }

    public static Integer getCurrentSpan() {
        Stack<Integer> stack = track.get();
        if (stack == null || stack.isEmpty()) {
            return null;
        }
        return stack.peek();
    }
}

package org.codetool;

public class TrackContext {
    private static final InheritableThreadLocal<Integer> trackLocal = new InheritableThreadLocal<>();

    public static void clear() {
        trackLocal.remove();
    }

    public static Integer getLinkId() {
        return trackLocal.get();
    }

    public static void setLinkId(Integer linkId) {
        trackLocal.set(linkId);
    }
}

package org.codetool;

import java.util.HashMap;
import java.util.Map;
import java.util.Stack;

import static org.codetool.WebApplication.logLevel;

public class HelloController {

    private HelloService helloService = new HelloService();

    public Map<String, Object> hello() {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) +"链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloController::hello() 方法开始执行, 开始时间:" + startTime);

        Map<String, Object> map = new HashMap<>();
        int a = helloService.m1();
        int b = helloService.m2();

        new Thread(() -> helloService.m3(a, b)).start();

        System.out.println(logLevel(parentSpan) +"链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloController::hello() 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();

        return map;
    }

}

package org.codetool;

import static org.codetool.WebApplication.logLevel;

public class HelloService {

    public int m1() {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m1() 方法开始执行, 开始时间:" + startTime);

        int res = 1;

        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m1() 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();

        return res;
    }


    public int m2() {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m2() 方法开始执行, 开始时间:" + startTime);

        int res = 2;

        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m2() 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();

        return res;
    }

    public void m3(int a, int b) {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m3(int, int) 方法开始执行, 开始时间:" + startTime);

        try {
            Thread.sleep(2000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

        m4(a % b);

        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m3(int, int) 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();
    }

    private void m4(int i) {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m4(int) 方法开始执行, 开始时间:" + startTime);


        System.out.println(i);

        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.HelloService::m4(int) 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();
    }

}

package org.codetool;

public class WebApplication {
    public static String logLevel(Integer span) {
        if (span == null) {
            return "";
        }

        StringBuilder sb = new StringBuilder();
        for (Integer i = 0; i <= span; i++) {
            sb.append("\t");
        }
        return sb.toString();
    }

    public static void main(String[] args) throws InterruptedException {
        Integer linkId = TrackManager.getCurrentSpan();
        if (null == linkId) {
            linkId = 0;
            TrackContext.setLinkId(linkId);
        }
        Integer parentSpan = TrackManager.getCurrentSpan();
        Integer entrySpan = TrackManager.createEntrySpan();
        long startTime = System.currentTimeMillis();
        System.out.println(logLevel(parentSpan) + "链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.WebApplication::main(String[] args) 方法开始执行, 开始时间:" + startTime);
        HelloController controller = new HelloController();
        controller.hello();
        Thread.sleep(5000);
        System.out.println(logLevel(parentSpan) +"链路追踪:[" + parentSpan + "-" + entrySpan + "] 方法:org.codetool.WebApplication::main(String[] args) 方法执行结束, 执行耗时:" + (System.currentTimeMillis() - startTime) + "ms");
        TrackManager.getExitSpan();
    }
}

编译运行

链路追踪:[null-0] 方法:org.codetool.WebApplication::main(String[] args) 方法开始执行, 开始时间:1626679482216
    链路追踪:[0-1] 方法:org.codetool.HelloController::hello() 方法开始执行, 开始时间:1626679482218
        链路追踪:[1-2] 方法:org.codetool.HelloService::m1() 方法开始执行, 开始时间:1626679482218
        链路追踪:[1-2] 方法:org.codetool.HelloService::m1() 方法执行结束, 执行耗时:0ms
        链路追踪:[1-2] 方法:org.codetool.HelloService::m2() 方法开始执行, 开始时间:1626679482218
        链路追踪:[1-2] 方法:org.codetool.HelloService::m2() 方法执行结束, 执行耗时:0ms
    链路追踪:[0-1] 方法:org.codetool.HelloController::hello() 方法执行结束, 执行耗时:43ms
    链路追踪:[0-1] 方法:org.codetool.HelloService::m3(int, int) 方法开始执行, 开始时间:1626679482262
        链路追踪:[1-2] 方法:org.codetool.HelloService::m4(int) 方法开始执行, 开始时间:1626679484262
1
        链路追踪:[1-2] 方法:org.codetool.HelloService::m4(int) 方法执行结束, 执行耗时:0ms
    链路追踪:[0-1] 方法:org.codetool.HelloService::m3(int, int) 方法执行结束, 执行耗时:2000ms
链路追踪:[null-0] 方法:org.codetool.WebApplication::main(String[] args) 方法执行结束, 执行耗时:5046ms

这里显示出来的调用顺序明显是存在问题的. 虽然 InheritableThreadLocal 会拷贝父线程中的值, 但是它是浅拷贝的. 当父线程中的 hello 方法执行完毕以后, hello 方法会调用 getExitSpan() 方法, 此时子线程中的 Stack<String> 中的值也会发生改变, 所以导致了调用顺序打印出来不对的问题. 如何避免这样的问题呢?

package com.codetool.common;

import java.util.Stack;

public class MyThreadLocal<T> extends InheritableThreadLocal<T> {

    @Override
    protected T childValue(T parentValue) {
        if (parentValue instanceof Stack) {
            Stack<Integer> copy = TrackManager.copy();
            return (T) copy;
        }
        return parentValue;
    }
}

这里我们自定义一个 ThreadLocal, 然后让这个 ThreadLocal 实现 InheritableThreadLocal 的 childValue 方法就可以实现数据深拷贝了. 

public class TrackManager {
    private static final MyThreadLocal<Stack<Integer>> track = new MyThreadLocal<>();
    ....
}

现在我们在代码中实现我们自己定义的 MyThreadLocal 来存储线程共享变量. 编译运行:

链路追踪:[null-0] 方法:org.codetool.WebApplication::main(String[] args) 方法开始执行, 开始时间:1627379202598
    链路追踪:[0-1] 方法:org.codetool.HelloController::hello() 方法开始执行, 开始时间:1627379202602
        链路追踪:[1-2] 方法:org.codetool.HelloService::m1() 方法开始执行, 开始时间:1627379202602
        链路追踪:[1-2] 方法:org.codetool.HelloService::m1() 方法执行结束, 执行耗时:0ms
        链路追踪:[1-2] 方法:org.codetool.HelloService::m2() 方法开始执行, 开始时间:1627379202602
        链路追踪:[1-2] 方法:org.codetool.HelloService::m2() 方法执行结束, 执行耗时:0ms
    链路追踪:[0-1] 方法:org.codetool.HelloController::hello() 方法执行结束, 执行耗时:65ms
        链路追踪:[1-2] 方法:org.codetool.HelloService::m3(int, int) 方法开始执行, 开始时间:1627379202667
            链路追踪:[2-3] 方法:org.codetool.HelloService::m4(int) 方法开始执行, 开始时间:1627379204667
1
            链路追踪:[2-3] 方法:org.codetool.HelloService::m4(int) 方法执行结束, 执行耗时:0ms
        链路追踪:[1-2] 方法:org.codetool.HelloService::m3(int, int) 方法执行结束, 执行耗时:2000ms

现在 m3 打印出来的的顺序就是正确的了.

之前我们是将 ThreadLocal 中的值深拷贝了一份到子线程中去的, 所以不会出现这种问题. 但是即使这个 InheritableThreadTLocal 是深拷贝, 碰到万恶的线程池还是要拉稀. 为了解决线程池的调用监控问题, 我们需要使用到 alibaba 开源的 TransmittableThreadLocal, 

<dependency>
    <groupId>com.alibaba</groupId>
    <artifactId>transmittable-thread-local</artifactId>
    <version>2.11.4</version>
</dependency>

然而, TransmittableThreadLocal 继承了 InnheritableThreadLocal, 也是从父线程中对值进行浅拷贝, 为了解决这种问题,  我们可以参考之前的 MyThreadLocal, 现在看一下怎么用这个东西在一个 springboot + springmvc + spring-data-jpa 中使用吧. 

回到起点, 重写编写一个 javaagent 项目, 监控  jdbc 层的 sql 执行, 因为数据库连接一直是所有 web 项目的性能瓶颈. 于是出现了一大堆的数据库连接池, 什么dbcp, c3p0, 德鲁伊, hikariCp...乱七八糟的. 数据库连接池是在服务启动后启动的, 本质上和我们的 tomcat 线程不搭边的. 而 TransmittableThreadLocal 可以解决这种问题. 具体解决原理参考文章: https://blog.csdn.net/y4x5M0nivSrJaY3X92c/article/details/106416414

有了上面的基本知识介绍, 接下来我们开始正式实现一个单机版的 APM 监控系统. 链接如下: https://blog.csdn.net/weixin_44231940/article/details/118901859