通过p6spy打印完整sql语句

概述

问题排查

在排查问题的时候，往往需要通过链路查看具体执行的sql语句，可是使用Mybatis或者JPA等框架时，打印的的sql总是带着?占位符，不能直接在数据库执行并且不够直观。

开发调试

在开发环境调试代码，往往需要打印执行的SQL语句来判断mybatis的SQL语句是否符合预期，尤其是我们的SQL语句使用了较多的标签时，只有真正的执行到了mybatis的标签解析器后，才能生成最终的SQL语句；当遇到SQL语句看似解析正常但是执行的时候却报错，在这个时候如果mybatis本身的SQL日志没有打印，将会是非常头疼的。

默认sql输出

引入p6spy

介绍

p6spy是一个开源项目，通常使用它来跟踪数据库操作，查看程序运行过程中执行的sql语句。官网地址：p6spy官网

原理

p6spy将应用的数据源给劫持了，应用操作数据库其实在调用p6spy的数据源，p6spy劫持到需要执行的sql或者hql之类的语句之后，他自己去调用一个realDatasource，再去操作数据库

应用场景

p6spy 可以输出日志到文件中、控制台、或者传递给 Log4j，而且还能配搭 SQL Profiler 或 IronTrackSQL 图形化监控 SQL 语句，监测到哪些语句的执行是耗时的，可逐个优化。

maven 坐标

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

数据源配置

# p6spy 驱动
xx.driver-class-name=com.p6spy.engine.spy.P6SpyDriver
# 原来url`jdbc：`后面添加`:p6spy`
xx.url=jdbc:p6spy:mysql://127.0.0.1:3306/xxx?useUnicode=true&characterEncoding=utf-8&zeroDateTimeBehavior=convertToNull&useSSL=false&allowMultiQueries=true&rewriteBatchedStatements=true&master=true

$\color{red}master=true配合主从使用$

spy.properties

# mysql 驱动
driverlist=com.mysql.jdbc.Driver
# 打印sql日志时间格式化
dateformat=yyyy-MM-dd HH:mm:ss:SSS
# 定义包含的日志级别，当日志级别属于此类型时，才能被记录，属性值有error, info, batch, debug, statement, commit, rollback 和result    
includecategories=debug,info,error,batch,statement,commit,rollback,result
# 自定义sql打印  
logMessageFormat=com.xxx.sql.P6SpySqlFormat

P6SpySqlFormat

@Slf4j
public class P6SpySqlFormat implements MessageFormattingStrategy {
 
    /**
     * 多个空格替换成一个空格
     */
    private static final Pattern PATTERN = Pattern.compile("\\s+");
 
    private static final String SQL = "select 1";
 
    public P6SpySqlFormat() {
    }
 
    @Override
    public String formatMessage(int connectionId, String now, long elapsed, String category, String prepared, String sql, String url) {
        if (StrUtil.isNotEmpty(sql) && !SQL.equalsIgnoreCase(sql)) {
            String sqlFormat = PATTERN.matcher(sql).replaceAll(" ") + ";";
            String masterSlave = Boolean.parseBoolean(url.substring(url.lastIndexOf("=") + 1)) ? "主库" : "从库";
            if (elapsed > 1000) {
                log.warn("p6spy | {} | connection {} | {} | {}ms | SQL执行时间超过1秒钟 |\n{}", now, connectionId, masterSlave, elapsed, sqlFormat);
            } else {
                log.info("p6spy | {} | connection {} | {} | {}ms |\n{}", now, connectionId, masterSlave, elapsed, sqlFormat);
            }
        }
        return null;
    }
}

SQL日志

打印实例
2021-12-27 09:55:13.140  INFO 44759 --- [nio-8004-exec-4] p6spy | 2021-12-27 09:55:13:140 | connection 0 | 主库 | 100ms |
INSERT INTO bd_user ( code, create_time, create_by, update_time, update_by, version, deleted, `source` ) VALUES ( 'xiongyan1', '2021-12-27 09:55:13', 'sys', '2021-12-27 09:55:13', 'sys', 0, 0, 0 );
  
2021-12-27 09:55:12.992  INFO 44759 --- [nio-8004-exec-4] p6spy | 2021-12-27 09:55:12:992 | connection 1 | 从库 | 45ms |
SELECT id,code,create_time AS createTime,create_by AS createBy,update_time AS updateTime,update_by AS updateBy,version,deleted,`source` FROM bd_user WHERE id=1;

附录: spy.properties详细说明

# 指定应用的日志拦截模块,默认为com.p6spy.engine.spy.P6SpyFactory
#modulelist=com.p6spy.engine.spy.P6SpyFactory,com.p6spy.engine.logging.P6LogFactory,com.p6spy.engine.outage.P6OutageFactory

# 真实JDBC driver , 多个以 逗号 分割 默认为空
#driverlist=

# 是否自动刷新 默认 flase
#autoflush=false

# 配置SimpleDateFormat日期格式 默认为空
#dateformat=

# 打印堆栈跟踪信息 默认flase
#stacktrace=false

# 如果 stacktrace=true，则可以指定具体的类名来进行过滤。
#stacktraceclass=

# 监测属性配置文件是否进行重新加载
#reloadproperties=false

# 属性配置文件重新加载的时间间隔，单位:秒 默认60s
#reloadpropertiesinterval=60

# 指定 Log 的 appender，取值：
#appender=com.p6spy.engine.spy.appender.Slf4JLogger
#appender=com.p6spy.engine.spy.appender.StdoutLogger
#appender=com.p6spy.engine.spy.appender.FileLogger

# 指定 Log 的文件名 默认 spy.log
#logfile=spy.log

# 指定是否每次是增加 Log，设置为 false 则每次都会先进行清空 默认true
#append=true

# 指定日志输出样式  默认为com.p6spy.engine.spy.appender.SingleLineFormat , 单行输出 不格式化语句
#logMessageFormat=com.p6spy.engine.spy.appender.SingleLineFormat
# 也可以采用  com.p6spy.engine.spy.appender.CustomLineFormat 来自定义输出样式, 默认值是%(currentTime)|%(executionTime)|%(category)|connection%(connectionId)|%(sqlSingleLine)
# 可用的变量为:
#   %(connectionId)            connection id
#   %(currentTime)             当前时间
#   %(executionTime)           执行耗时
#   %(category)                执行分组
#   %(effectiveSql)            提交的SQL 换行
#   %(effectiveSqlSingleLine)  提交的SQL 不换行显示
#   %(sql)                     执行的真实SQL语句，已替换占位
#   %(sqlSingleLine)           执行的真实SQL语句，已替换占位 不换行显示
#customLogMessageFormat=%(currentTime)|%(executionTime)|%(category)|connection%(connectionId)|%(sqlSingleLine)

# date类型字段记录日志时使用的日期格式 默认dd-MMM-yy
#databaseDialectDateFormat=dd-MMM-yy

# boolean类型字段记录日志时使用的日期格式 默认boolean 可选值numeric
#databaseDialectBooleanFormat=boolean

# 是否通过jmx暴露属性 默认true
#jmx=true

# 如果jmx设置为true 指定通过jmx暴露属性时的前缀 默认为空
# com.p6spy(.<jmxPrefix>)?:name=<optionsClassName>
#jmxPrefix=

# 是否显示纳秒 默认false
#useNanoTime=false

# 实际数据源 JNDI
#realdatasource=/RealMySqlDS
# 实际数据源 datasource class
#realdatasourceclass=com.mysql.jdbc.jdbc2.optional.MysqlDataSource

# 实际数据源所携带的配置参数 以 k=v 方式指定 以 分号 分割
#realdatasourceproperties=port;3306,serverName;myhost,databaseName;jbossdb,foo;bar

# jndi数据源配置
# 设置 JNDI 数据源的 NamingContextFactory。
#jndicontextfactory=org.jnp.interfaces.NamingContextFactory
# 设置 JNDI 数据源的提供者的 URL。
#jndicontextproviderurl=localhost:1099
# 设置 JNDI 数据源的一些定制信息，以分号分隔。
#jndicontextcustom=java.naming.factory.url.pkgs;org.jboss.naming:org.jnp.interfaces

# 是否开启日志过滤 默认false， 这项配置是否生效前提是配置了 include/exclude/sqlexpression
#filter=false

# 过滤 Log 时所包含的表名列表，以逗号分隔 默认为空
#include=
# 过滤 Log 时所排除的表名列表，以逗号分隔 默认为空
#exclude=

# 过滤 Log 时的 SQL 正则表达式名称  默认为空
#sqlexpression=

#显示指定过滤 Log 时排队的分类列表，取值: error, info, batch, debug, statement,
#commit, rollback, result and resultset are valid values
# (默认 info,debug,result,resultset,batch)
#excludecategories=info,debug,result,resultset,batch

# 是否过滤二进制字段
# (default is false)
#excludebinary=false

# P6Log 模块执行时间设置，整数值 (以毫秒为单位)，只有当超过这个时间才进行记录 Log。 默认为0
#executionThreshold=

# P6Outage 模块是否记录较长时间运行的语句 默认false
# outagedetection=true|false
# P6Outage 模块执行时间设置，整数值 （以秒为单位)），只有当超过这个时间才进行记录 Log。 默认30s
# outagedetectioninterval=integer time (seconds)

总结

关闭mybatis默认的sql输出
开启p6spy的sql输出

便于通过完整sql排查问题
可以监控慢sql输出
系统日志文件变小节约磁盘空间
性能没有任何影响

P6spy打印Sql日志