JDBC使用p6spy记录实际执行SQL方法【解决SQL打印两次问题】

p6spy介绍

p6spy 是一个开源的 JDBC 数据源代理工具，主要用于拦截和记录应用程序与数据库之间的所有 SQL 操作，方便开发者进行 SQL 调试、性能监控和问题排查。
p6spy可以打印实际执行的sql，在开发过程中方便调试，和使用框架无关，Mybatis和Hibernate等都可以使用。

使用方法

1.引入p6spy依赖

        <dependency><groupId>p6spy</groupId><artifactId>p6spy</artifactId><version>3.9.1</version></dependency>

2.修改数据库连接信息，这里我使用的是Druid连接池

      oracleDataSource = new DruidDataSource();// 替换jdbcUrl为p6spy代理格式
//        oracleDataSource.setUrl("jdbc:oracle:thin:@10.5.1.22:1521/ORCL");oracleDataSource.setUrl("jdbc:p6spy:oracle:thin:@10.5.1.22:1521/ORCL");oracleDataSource.setUsername("ORACLE_USERNAME");oracleDataSource.setPassword("ORACLE_PASSWORD");// 这里使用的Druid连接池，不支持p6spy的自动装配，指定p6spy的代理类oracleDataSource.setDriverClassName("com.p6spy.engine.spy.P6SpyDriver");

3.在resource目录下创建配置文件spy.properties

# 指定日志实现，这里使用 SLF4J 输出日志
appender=com.p6spy.engine.spy.appender.Slf4JLogger# 默认为单行输出，这里指定多行日志输出格式，增加可读性
logMessageFormat=com.p6spy.engine.spy.appender.MultiLineFormat

4. 控制台成功打印日志

10:58:53.784 [main] INFO p6spy - #1732071533784 | took 1ms | statement | connection 4| url jdbc:p6spy:oracle:thin:@10.5.1.22:1521/ORCL
SELECT 1 FROM DUAL
SELECT 1 FROM DUAL;
10:58:53.798 [main] INFO p6spy - #1732071533798 | took 12ms | statement | connection 4| url jdbc:p6spy:oracle:thin:@10.5.1.22:1521/ORCL
SELECT * FROM cms_mid_table WHERE table_module='CIF'
SELECT * FROM cms_mid_table WHERE table_module='CIF';

SQL打印两遍

原因

查看MessageFormattingStrategy代码，很简单，就是将参数组装成打印结果

public class MultiLineFormat implements MessageFormattingStrategy {@Overridepublic String formatMessage(final int connectionId, final String now, final long elapsed, final String category, final String prepared, final String sql, final String url) {return "#" + now + " | took " + elapsed + "ms | " + category + " | connection " + connectionId + "| url " + url + "\n" + prepared + "\n" + sql +";";}
}

而我在代码中是使用apache工具类QueryRunner#excute，直接执行sql的，没有使用预编译参数

    public void test()  {QueryRunner queryRunner = new QueryRunner();try {queryRunner.execute("DELETE FROM cms_mid_table WHERE table_module='CIF'", ETLConnectionPool.getObConnection());} catch (SQLException e) {throw new RuntimeException(e);}}

QueryRunner内部使用的是PrepareStatement的子类CallableStatement

    private int execute(Connection conn, boolean closeConn, String sql, Object... params) throws SQLException {if (conn == null) {throw new SQLException("Null connection");}if (sql == null) {if (closeConn) {close(conn);}throw new SQLException("Null SQL statement");}CallableStatement stmt = null;int rows = 0;try {stmt = this.prepareCall(conn, sql);this.fillStatement(stmt, params);stmt.execute();rows = stmt.getUpdateCount();this.retrieveOutParameters(stmt, params);} catch (SQLException e) {this.rethrow(e, sql, params);} finally {close(stmt);if (closeConn) {close(conn);}}return rows;}

因为我是直接执行的具体的SQL，所以预编译对象和实际直接的sql相同，导致打印结果看上去是相同的SQL打印了两遍。

解决方法

1. 创建自定义日志格式化类

@Slf4j
public class CustomLogFormatter implements MessageFormattingStrategy {@Overridepublic String formatMessage(int connectionId, String now, long elapsed, String category, String prepared, String sql, String url) {// 自定义sql日志内容return "#" + now + " | took " + elapsed + "ms | " + category + " | connection " + connectionId + "| url " + url+ "\n" + sql.replaceAll(" {2,}", " ") + ";\n";}
}

2. 在spy.properties配置文件中指定自定义格式类

# 使用 SLF4J 输出日志
appender=com.p6spy.engine.spy.appender.Slf4JLogger# 使用自定义日志格式，实现只输出最终sql，不输出prepare对象
logMessageFormat=com.dhcc.utils.CustomLogFormatter