【p6spy学习之一】p6spy使用
一、介绍
p6spy是一个开源项目，通常使用它来跟踪数据库操作，查看程序运行过程中执行的sql语句。
1、原理
p6spy将应用的数据源给劫持了，应用操作数据库其实在调用p6spy的数据源，p6spy劫持到需要执行的sql或者hql之类的语句之后，他自己去调用一个realDatasource，再去操作数据库，
包括P6Log和P6Outage两个模块：P6Log 用来拦截和记录任务应用程序的 JDBC 语句，P6Outage 专门用来检测和记录超过配置条件里时间的 SQL 语句.
2、应用场景
p6spy 可以输出日志到文件中、控制台、或者传递给 Log4j，而且还能配搭 SQL Profiler 或 IronTrackSQL 图形化监控 SQL 语句，监测到哪些语句的执行是耗时的，逐个优化。
3、配置文件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 , 多个以 逗号 分割 默认为空,比如：com.mysql.jdbc.Driver,oracle.jdbc.driver.OracleDriver #driverlist= # 是否自动刷新 默认 flase #autoflush=false # 配置SimpleDateFormat日期格式 默认为空 #dateformat=yyyy-MM-dd HH:mm:ss # 打印堆栈跟踪信息 默认flase #stacktrace=false # 如果 stacktrace=true，则可以指定具体的类名来进行过滤。 #stacktraceclass= # 监测属性配置文件是否进行重新加载 #reloadproperties=false # 属性配置文件重新加载的时间间隔，单位:秒 默认60s #reloadpropertiesinterval=60 # 指定 Log 的 appender，取值：分别是使用Log4j日志系统，打印控制台，打印到文件 #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) #举例 #logMessageFormat=com.p6spy.engine.spy.appender.CustomLineFormat #customLogMessageFormat=%(currentTime) | SQL耗时： %(executionTime) ms | 连接信息： %(category)-%(connectionId) | 执行语句： %(sql) # 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)
二、Springboot整合p6spy
1、引入p6spy依赖
<?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 https://maven.apache.org/xsd/maven-4.0.0.xsd"> <modelVersion>4.0.0</modelVersion> <parent> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-parent</artifactId> <version>2.1.9.RELEASE</version> <relativePath/> <!-- lookup parent from repository --> </parent> <groupId>com.wjy</groupId> <artifactId>p6spydemo</artifactId> <version>0.0.1-SNAPSHOT</version> <name>p6spydemo</name> <description>Demo project for Spring Boot</description> <properties> <java.version>1.8</java.version> </properties> <dependencies> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-web</artifactId> </dependency> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-jdbc</artifactId> </dependency> <dependency> <groupId>mysql</groupId> <artifactId>mysql-connector-java</artifactId> <scope>runtime</scope> </dependency> <dependency> <groupId>p6spy</groupId> <artifactId>p6spy</artifactId> <version>3.7.0</version> </dependency> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-test</artifactId> <scope>test</scope> </dependency> </dependencies> <build> <plugins> <plugin> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-maven-plugin</artifactId> </plugin> </plugins> </build> </project>
2、修改数据源连接配置
spring: datasource: driver-class-name: com.p6spy.engine.spy.P6SpyDriver type: com.zaxxer.hikari.HikariDataSource url: jdbc:p6spy:mysql://127.0.0.1:3306/test?useSSL=false&autoReconnect=true&useUnicode=true&characterEncoding=utf-8&serverTimezone=UTC username: root password: 123456
3、引入配置文件spy.properties
module.log=com.p6spy.engine.logging.P6LogFactory,com.p6spy.engine.outage.P6OutageFactory # 自定义日志打印 logMessageFormat=com.wjy.log.P6SpyLogger #logMessageFormat=com.p6spy.engine.spy.appender.SingleLineFormat #logMessageFormat=com.p6spy.engine.spy.appender.CustomLineFormat #customLogMessageFormat=%(currentTime) | SQL耗时： %(executionTime) ms | 连接信息： %(category)-%(connectionId) | 执行语句： %(sql) # 使用控制台记录sql appender=com.p6spy.engine.spy.appender.StdoutLogger ## 配置记录Log例外 excludecategories=info,debug,result,batc,resultset # 设置使用p6spy driver来做代理 deregisterdrivers=true # 日期格式 dateformat=yyyy-MM-dd HH:mm:ss # 实际驱动 driverlist=com.mysql.jdbc.Driver # 是否开启慢SQL记录 outagedetection=true # 慢SQL记录标准 秒 outagedetectioninterval=2
代码结构：
测试：
2019-10-18 09:33:04.714 INFO 4980 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet' 2019-10-18 09:33:04.714 INFO 4980 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet' 2019-10-18 09:33:04.718 INFO 4980 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 4 ms 2019-10-18 09:33:04.744 INFO 4980 --- [nio-8080-exec-1] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting... Loading class `com.mysql.jdbc.Driver'. This is deprecated. The new driver class is `com.mysql.cj.jdbc.Driver'. The driver is automatically registered via the SPI and manual loading of the driver class is generally unnecessary. 2019-10-18 09:33:04.915 INFO 4980 --- [nio-8080-exec-1] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed. [ 2019-10-18T09:33:04.982 ] --- | took 39ms | insert into users values(null,?,?)|statement | connection 0 insert into users values(null,'wangjunyu',20);
4、格式化日志
logMessageFormat：指定日志格式化类
(1)默认:com.p6spy.engine.spy.appender.SingleLineFormat , 单行输出 不格式化语句
2019-10-18 10:05:49|28|statement|connection 0|insert into users values(null,?,?)|insert into users values(null,'wjy',20)
(2)com.p6spy.engine.spy.appender.CustomLineFormat，需要配合customLogMessageFormat指定格式
# 可用的变量为:
# %(connectionId) connection id
# %(currentTime) 当前时间
# %(executionTime) 执行耗时
# %(category) 执行分组
# %(effectiveSql) 提交的SQL 换行
# %(effectiveSqlSingleLine) 提交的SQL 不换行显示
# %(sql) 执行的真实SQL语句，已替换占位
# %(sqlSingleLine) 执行的真实SQL语句，已替换占位 不换行显示
举例：
customLogMessageFormat=%(currentTime) | SQL耗时： %(executionTime) ms | 连接信息： %(category)-%(connectionId) | 执行语句： %(sql)
2019-10-18 10:09:55 | SQL耗时： 36 ms | 连接信息： statement-0 | 执行语句： insert into users values(null,'wjy',20)
(3)实现MessageFormattingStrategy接口，重写formatMessage方法
package com.wjy.log; import com.p6spy.engine.spy.appender.MessageFormattingStrategy; import java.time.LocalDateTime; public class P6SpyLogger implements MessageFormattingStrategy { /** * @Desc: 重写日志格式方法 * now:当前时间 * elapsed:执行耗时 * category：执行分组 * prepared：预编译sql语句 * sql:执行的真实SQL语句，已替换占位 */ @Override public String formatMessage(int connectionId, String now, long elapsed, String category, String prepared, String sql) { return !"".equals(sql.trim()) ? "[ " + LocalDateTime.now() + " ] --- | took " + elapsed + "ms | " + prepared + "|" + category + " | connection " + connectionId + "\n " + sql + ";" : ""; } }
[ 2019-10-18T09:33:04.982 ] --- | took 39ms | insert into users values(null,?,?)|statement | connection 0 insert into users values(null,'wangjunyu',20);
三、问题：
创建数据库连接时报错：
2019-10-18 07:58:25.265 ERROR 4968 --- [nio-8080-exec-1] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLNonTransientConnectionException: Could not create connection to database server. Attempted reconnect 3 times. Giving up.] with root cause com.mysql.cj.exceptions.InvalidConnectionAttributeException: The server time zone value '�й���ʱ��' is unrecognized or represents more than one time zone. You must configure either the server or JDBC driver (via the serverTimezone configuration property) to use a more specifc time zone value if you want to utilize time zone support.
原因和解决措施：指定连接时区：在jdbc连接串后面加上 &serverTimezone=UTC 即可
参考：
学习技术不是用来写HelloWorld和Demo的，而是要用来解决线上系统的真实问题的.
