利用javaagent监控sql查询时长

背景

公司自研且上线了一个管理系统，随着用户越来越多，数据量不断增长，部分问题逐渐暴露了出来，其中就包含了sql慢查询的问题，那么本章主要介绍如何通过javaagent实现无入侵性的方式监控并强制停止慢查询的sql。

所谓慢查询：就是运行时间比较长的sql
慢查询的危害：
1、慢查会占用mysql大量内存，如果大量慢sql同时执行，会使数据库性能极具降低。
2、慢查的过程中，会阻塞数据库DDL脚本，包括实时备份，对于实时备份的场景来说不可容忍。
3、慢查会导致服务端无法在指定时间段内反馈结果给客户端，导致进程被kill或连接超时等因素。
4、影响用户体验，sql执行时间越长，用户在客户端等待时间越久。

什么是javaagent

Java Agent 又叫做 Java 探针，在 JDK1.5 引入的一种可以动态修改 Java 字节码的技术。Java 类编译之后形成字节码被 JVM 执行，在 JVM 执行这些字节码之前获取这些字节码信息，并且通过字节码转换器对这些字节码进行修改，来完成一些额外的功能。

即在java文件被编译为class文件后，jvm加载class字节码之前，去修改字节码的内容

javaagent初体验

新建maven项目，并创建一个javaagent的启动类

import java.lang.instrument.Instrumentation;

/**
 * agent入口.
 *
 * @author ZhouZhou
 * @date 2023/4/11 21:18
 */
public class HelloJavaagent {

    public static void premain(String agentArgs, Instrumentation inst) {
        System.out.println("hello");
    }
}

在jvm启动时会先运行premain方法，也就是该方法是在main方法执行前调用的。
这样的一个javaagent项目其实就已经完成了。
要运行这个项目还需要做两个步骤
1、pom中增加打包的依赖

<plugin>
        <groupId>org.apache.maven.plugins</groupId>
        <artifactId>maven-jar-plugin</artifactId>
        <version>3.1.0</version>
        <configuration>
           <archive>
              <manifest>
                 <addClasspath>true</addClasspath>
              </manifest>
              <manifestEntries>
                 <Premain-Class>com.demo.HelloJavaagent</Premain-Class>
                 <Can-Redefine-Classes>true</Can-Redefine-Classes>
                 <Can-Retransform-Classes>true</Can-Retransform-Classes>
                 <Can-Set-Native-Method-Prefix>true</Can-Set-Native-Method-Prefix>
              </manifestEntries>
           </archive>
         </configuration>
</plugin>

jvm启动后制定调用com.demo.HelloJavaagent中的premain方法。
2、在运行被代理项目时，两种方式，第一种可以直接通过java -javaagent:/agent.jar -jar xxx被代理.jar来运行， 第二种在测试时可以通过设置idea启动参数来设置启动时运行javaagent的jar包。

运行被代理项目的main方法

在程序运行后，先打印了hello
以上就可以完成最基本的一个javaagent项目，可以在不修改被代理项目的前提下，完成一些额外操作。

javassist初体验

上面简单了解了javaagent的使用，那么如何通过javaagent的方式去修改字节码，可以通过asm，javassist等技术来解决，本章主要介绍使用javassist技术来修改字节码文件。

javassist主要的优点，在于简单，快速，直接使用java编码的形式，不需要去了解jvm指令，就能动态改变类的结构，或者动态生成类等等。

import java.lang.instrument.Instrumentation;

import com.sqlmonitoragent.transformer.TestTransformer;

public class TestJavassist {

    public static void premain(String agentArgs, Instrumentation inst) {
        inst.addTransformer(new TestTransformer());
    }
}

import java.io.ByteArrayInputStream;
import java.lang.instrument.ClassFileTransformer;
import java.lang.instrument.IllegalClassFormatException;
import java.security.ProtectionDomain;

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

public class TestTransformer implements ClassFileTransformer {

    private static final String PATH = "com/demo/TestController";
    private static final String METHOD = "test";

    @Override
    public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined, ProtectionDomain protectionDomain, byte[] classfileBuffer) throws IllegalClassFormatException {
        if (className == null || !className.equals(PATH)) {
            return classfileBuffer;
        }
        try {
            ClassPool pool = ClassPool.getDefault();
            pool.insertClassPath(new LoaderClassPath(loader));
            CtClass cc = pool.makeClass(new ByteArrayInputStream(classfileBuffer));
            CtMethod queryMethod = cc.getDeclaredMethod(METHOD);
            queryMethod.insertBefore("System.out.println(\"A\");");
            queryMethod.insertAfter("System.out.println(\"C\");");
            return cc.toBytecode();
        } catch (Exception e) {
            e.printStackTrace();
        }
        return classfileBuffer;
    }

}

ClassFileTransformer接口用于改变运行时的字节码，这个改变的时机是在jvm加载这个类之前，那么此处的代码表示在加载类时，先判断是不是我想要改变的类（全路径），如果当前加载的类是com/demo/TestController，那么通过javassist的ClassPool获取到该类的字节码，最终获取到该类的test方法，获取到方法后就可以来修改这个方法内部的字节码了，这里通过insertBefore在test方法的首行加入一段代码输出A，通过insertAfter在test方法的末尾加入一段代码输出C，最终将修改后的字节码返回，此时jvm即将要加载的TestController类就已经发生了改变。

在被代理项目中新建一个测试接口

@RestController
@RequestMapping("/test")
public class TestController {

    @GetMapping("/test")
    public RespDTO<String> test() {
        System.out.println("B");
        return RespDTO.success();
    }
}

该接口中有个test方法，输出了B。
在运行时指定javaagent的jar，运行效果

以上就是通过javassist在程序启动后动态的修改了某个文件的代码。

监控mybatis的sql查询时间

前面了解了什么是java探针以及如何通过javassist来修改字节码
现在回归主题，如何去监控sql的查询时间
在我们项目中使用的是mybatis持久化框架
为了以最少的代码改动来监控sql的查询时间，可以从mybatis的源码中入手

/**
 *    Copyright 2009-2016 the original author or authors.
 *
 *    Licensed under the Apache License, Version 2.0 (the "License");
 *    you may not use this file except in compliance with the License.
 *    You may obtain a copy of the License at
 *
 *       http://www.apache.org/licenses/LICENSE-2.0
 *
 *    Unless required by applicable law or agreed to in writing, software
 *    distributed under the License is distributed on an "AS IS" BASIS,
 *    WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 *    See the License for the specific language governing permissions and
 *    limitations under the License.
 */
package org.apache.ibatis.executor.statement;

import java.sql.Connection;
import java.sql.SQLException;
import java.sql.Statement;
import java.util.List;

import org.apache.ibatis.cursor.Cursor;
import org.apache.ibatis.executor.parameter.ParameterHandler;
import org.apache.ibatis.mapping.BoundSql;
import org.apache.ibatis.session.ResultHandler;

/**
 * @author Clinton Begin
 */
public interface StatementHandler {

  Statement prepare(Connection connection, Integer transactionTimeout)
      throws SQLException;

  void parameterize(Statement statement)
      throws SQLException;

  void batch(Statement statement)
      throws SQLException;

  int update(Statement statement)
      throws SQLException;

  <E> List<E> query(Statement statement, ResultHandler resultHandler)
      throws SQLException;

  <E> Cursor<E> queryCursor(Statement statement)
      throws SQLException;

  BoundSql getBoundSql();

  ParameterHandler getParameterHandler();

}

StatementHandler是mybatis的核心之一，该抽象接口主要用于选择当前执行的sql应该使用哪一个策略

此次修改主要针对其中的一个策略：PreparedStatementHandler的query方法，进行增强。

package org.apache.ibatis.executor.statement;

import java.sql.Connection;
import java.sql.PreparedStatement;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.sql.Statement;
import java.util.List;

import org.apache.ibatis.cursor.Cursor;
import org.apache.ibatis.executor.Executor;
import org.apache.ibatis.executor.keygen.Jdbc3KeyGenerator;
import org.apache.ibatis.executor.keygen.KeyGenerator;
import org.apache.ibatis.mapping.BoundSql;
import org.apache.ibatis.mapping.MappedStatement;
import org.apache.ibatis.mapping.ResultSetType;
import org.apache.ibatis.session.ResultHandler;
import org.apache.ibatis.session.RowBounds;

/**
 * @author Clinton Begin
 */
public class PreparedStatementHandler extends BaseStatementHandler {

  public PreparedStatementHandler(Executor executor, MappedStatement mappedStatement, Object parameter, RowBounds rowBounds, ResultHandler resultHandler, BoundSql boundSql) {
    super(executor, mappedStatement, parameter, rowBounds, resultHandler, boundSql);
  }

  @Override
  public int update(Statement statement) throws SQLException {
    PreparedStatement ps = (PreparedStatement) statement;
    ps.execute();
    int rows = ps.getUpdateCount();
    Object parameterObject = boundSql.getParameterObject();
    KeyGenerator keyGenerator = mappedStatement.getKeyGenerator();
    keyGenerator.processAfter(executor, mappedStatement, ps, parameterObject);
    return rows;
  }

  @Override
  public void batch(Statement statement) throws SQLException {
    PreparedStatement ps = (PreparedStatement) statement;
    ps.addBatch();
  }

  @Override
  public <E> List<E> query(Statement statement, ResultHandler resultHandler) throws SQLException {
    PreparedStatement ps = (PreparedStatement) statement;
    ps.execute();
    return resultSetHandler.handleResultSets(ps);
  }

  @Override
  public <E> Cursor<E> queryCursor(Statement statement) throws SQLException {
    PreparedStatement ps = (PreparedStatement) statement;
    ps.execute();
    return resultSetHandler.handleCursorResultSets(ps);
  }

  @Override
  protected Statement instantiateStatement(Connection connection) throws SQLException {
    String sql = boundSql.getSql();
    if (mappedStatement.getKeyGenerator() instanceof Jdbc3KeyGenerator) {
      String[] keyColumnNames = mappedStatement.getKeyColumns();
      if (keyColumnNames == null) {
        return connection.prepareStatement(sql, PreparedStatement.RETURN_GENERATED_KEYS);
      } else {
        return connection.prepareStatement(sql, keyColumnNames);
      }
    } else if (mappedStatement.getResultSetType() == ResultSetType.DEFAULT) {
      return connection.prepareStatement(sql);
    } else {
      return connection.prepareStatement(sql, mappedStatement.getResultSetType().getValue(), ResultSet.CONCUR_READ_ONLY);
    }
  }

  @Override
  public void parameterize(Statement statement) throws SQLException {
    parameterHandler.setParameters((PreparedStatement) statement);
  }

}

在执行查询sql时，最终会调用到query方法，我们就可以针对该方法做字节码的修改，在query方法的首行和末尾加入计算时间的代码。

import java.lang.instrument.Instrumentation;

import com.xiakuan.sqlmonitoragent.transformer.MybatisTransformer;

/**
 * agent入口.
 *
 * @author ZhouZhou
 * @date 2023/4/7 20:25
 */
public class MybatisAgent {

    public static void premain(String agentArgs, Instrumentation inst) {
        inst.addTransformer(new MybatisTransformer(agentArgs));
    }
}

import java.io.ByteArrayInputStream;
import java.lang.instrument.ClassFileTransformer;
import java.lang.instrument.IllegalClassFormatException;
import java.security.ProtectionDomain;

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

/**
 * 监控mybatis的PreparedStatementHandler，每次查询时判断sql时效是否大于x时间.
 *
 * @author ZhouZhou
 * @date 2023/4/7 20:30
 */
public class MybatisTransformer implements ClassFileTransformer {

    private static final String PLACEHOLDER_TIME_KEY = "#TIME";
    private static String PLACEHOLDER_TIME_VAL = "1000";
    private static String beforeCode = "com.sqlmonitoragent.constant.Constant.init();";
    private static String afterCode =
        "long endTime = System.currentTimeMillis();"
            + "long r = endTime - com.sqlmonitoragent.constant.Constant.get();"
            + "System.out.println(\"执行时间: \" + r + \"ms\");"
            + "if (r > #TIME) {"
            + "    throw new RuntimeException(\"sql执行时间超过#TIMEms\");"
            + "}";
    private static final String STATEMENT_PATH = "org/apache/ibatis/executor/statement/PreparedStatementHandler";
    private static final String STATEMENT_METHOD = "query";

    public MybatisTransformer(String startArgs) {
        System.out.println("javaagent启动参数:" + startArgs);
        initialization(startArgs);
        System.out.println("监控mybatis查询sql的时效设置时间为【" + PLACEHOLDER_TIME_VAL + "】毫秒");
    }

    @Override
    public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined, ProtectionDomain protectionDomain, byte[] classfileBuffer) throws IllegalClassFormatException {
        if (className == null || !className.equals(STATEMENT_PATH)) {
            return classfileBuffer;
        }
        try {
            ClassPool pool = ClassPool.getDefault();
            pool.insertClassPath(new LoaderClassPath(loader));
            CtClass cc = pool.makeClass(new ByteArrayInputStream(classfileBuffer));
            CtMethod queryMethod = cc.getDeclaredMethod(STATEMENT_METHOD);
            queryMethod.insertBefore(beforeCode);
            String after =
                afterCode.replaceAll(PLACEHOLDER_TIME_KEY, PLACEHOLDER_TIME_VAL);
            queryMethod.insertAfter(after);
            return cc.toBytecode();
        } catch (Exception e) {
            e.printStackTrace();
            System.err.println("写入失败: " + e.getMessage());
        }
        return classfileBuffer;
    }

    private void initialization(String startArgs) {
        if (startArgs != null && !startArgs.trim().equals("")) {
            PLACEHOLDER_TIME_VAL = startArgs.trim();
        }
    }

}

public class Constant {

    private static final ThreadLocal<Long> startTime = new ThreadLocal<>();

    public static void init() {
        startTime.set(System.currentTimeMillis());
    }

    public static long get() {
        return startTime.get();
    }
}

该代码主要实现监控查询sql的时间，如果超过设置的时间，就抛出一个RuntimeException异常
在MybatisTransformer中加入了一个构造方法，主要用于传入javaagent的启动参数，此处用作设置sql允许的时间，默认是1000，可以在启动时配置，通过 -javaagent:/xxx.jar=2000来修改，transform方法会拦截所有要加载的类，所以在做增强时我先判断了一下当前加载的类是不是我想要修改的类，即org/apache/ibatis/executor/statement/PreparedStatementHandler，
如果当前加载的类是我想要增强的类，就通过javassist的CtClass获取到该类，后通过getDeclaredMethod获取到query方法，在首行加入了一段代码，Constant.init()，调用该方法后会初始化当前时间存储在threadLocal当中，在尾行通过**Constant.get()**即可获取到开始时间，判断结束时间与开始时间的毫秒数是否大于启动时设置的参数（默认是1000），如果大于，就抛出异常。
为了方便测试，我将启动参数的时间修改为10毫秒,效果如下：

执行时间: 51ms
Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@e1ad010]
2023-04-11 20:21:32.023 ERROR [,0013ccb50d06c8ef,0013ccb50d06c8ef,true] 81035 --- [nio-8301-exec-3] c.d.x.b.exception.BasicExceptionHandler  : nested exception is org.apache.ibatis.exceptions.PersistenceException: 
### Error querying database.  Cause: java.lang.RuntimeException: sql执行时间超过10ms
### The error occurred while handling results
### SQL: select count(1) from test where no = '123'
### Cause: java.lang.RuntimeException: sql执行时间超过10ms

最后解释一下Constant这个类，这是我定义的一个静态类，主要用于存储变量，PreparedStatementHandler的query方法有并发问题，所以通过threadLocal来与线程绑定
在insertBefore方法中调用了Constant的init来初始化了时间，而不是通过直接加入一个变量的方式比如：

long startTime = System.currentTimeMillis();

如果这样做的话，在insertAfter中会因为作用域的问题获取不到startTime，从而会报找不到startTime这个字段的异常，这是因为insertBefore和insertAfter是分开的，可以理解为

public void test() {
        // insertBefore
        {
            long startTime = System.currentTimeMillis();
        }
        {
            // executeSql.query();
        }
        // insertAfter
        {
        	// 此处获取不到startTime
            System.currentTimeMillis() - startTime;
        }
    }

所以我通过使用静态类+threadLocal的方式解决了作用域的问题。

以上就是关于如何通过javaagent的方式在程序启动期间动态修改字节码。


留下人生足迹，一步一个脚印