【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 即可

 

本文代碼

參考：

使用P6Spy監控你的Spring boot數據庫操作
官方文檔