窺探p6spy的實現原理，抽取核心程式碼完成自己的SQL執行監控器
某一天線上專案突然炸了，報障說出現系統登入不了、資料查詢超慢等一系列問題...奇怪，之前明明還跑的好好的，怎麼會這樣子了呢？後來我們的資料庫大神（還是妹子哦）查了資料庫，統計執行比較耗時的SQL語句，對其中的一些欄位臨時加了索引，問題算是暫時解決了，給她點個贊QAQ。
這個時候，我就萌發了一個想法，可否在專案裡面引入一個監控、記錄SQL執行情況的功能，並提供查詢介面和顯示介面。
說幹就幹，首先想到的是看一下當前已有哪些現成的工具。
之前，接觸過赫赫有名的阿里開源的資料來源Druid（https://github.com/alibaba/druid），專為監控而生，效能也不低。二話不說，馬上百度一波教程，很快引進了專案並看到了效果，功能很齊全，牛逼！
由於專案已經使用了HikariCP資料庫連線池（號稱最快的），雖然可以通過配置實現Druid和HikariCP隨時切換，但是感覺不是那麼好，而且暫時還需要不到這麼多的功能（比如URI監控等），就忍痛割愛，放棄Druid了。
然後，又找到了MyBatis和Hibernate的攔截器。看了一波，Mybatis的攔截器是可以實現我需要的功能的；但是，公司使用了Hibernate，它的攔截器就不是那麼友好了，反正是沒有找到我需要的，具體你們可以去研究研究。
接著，偶然機會看到了p6spy，這玩意從底層的Connection、Statement（PreparedStatement）、ResultSet入手去做攔截、裝飾，很有想法，我很喜歡。
最後，發現p6spy預設是將監控情況輸出到日誌的，並不能實時檢視（其實也可以通過重寫它的處理方法，在裡面實現自己的功能）。
編了一大堆，其實就是我對它的原始碼感興趣而已。。。因此，廢話不說了，還是直入主題吧！
一、認識p6spy
github地址：https://github.com/p6spy/p6spy
官方介紹：P6Spy is a framework that enables database data to be seamlessly intercepted and logged with no code changes to existing application. The P6Spy distribution includes P6Log, an application which logs all JDBC transactions for any Java application.
翻譯過來就是，P6Spy是一個框架，它可以無縫地攔截和記錄資料庫資料，而無需更改現有應用程式的程式碼。P6Spy發行版包括P6Log，這是一個為任何Java應用程式記錄所有JDBC事務的應用程式。
具體使用不說了，百度教程一大堆，文章重心不在此。
二、p6spy實現原理
原始碼涉及的設計模式：裝飾者模式、觀察者模式、工廠模式、單例模式......
1、首先，我們之前使用jdbc都寫過這樣的程式碼吧：String driver = xxx；Class.forName(driver)。這裡，需要我們將driver設定成com.p6spy.engine.spy.P6SpyDriver，然後呼叫Class.forName(...)時會對這個類進行載入和連線。初始化的時候，會執行靜態程式碼塊，將驅動註冊到DriverManager裡（registerDriver方法會檢查classpath有沒有實現了Driver介面的這個類）。
static {
try {
DriverManager.registerDriver(P6SpyDriver.instance);
} catch (SQLException e) {
throw new IllegalStateException("Could not register P6SpyDriver with DriverManager", e);
}
}2、DriverManager.getConnection(...)的時候，會遍歷所有已註冊的驅動資訊，判斷每一個驅動跟所填的URL是否匹配（所有驅動都強制實現了Driver的acceptsURL方法）。根據我們填的URL以jdbc:p6spy:開頭，最終確定了Driver是P6SpyDriver。
@Override
public boolean acceptsURL(final String url) {
return url != null && url.startsWith("jdbc:p6spy:");
}3、獲取連線最終會呼叫到具體驅動類的connect(...)方法。首先，P6SpyDriver的實現裡面，它先要獲得實際的、真實的資料庫驅動（Oracle還是Mysql），怎麼獲得呢？把我們填寫的url的"p6spy:"去掉就得到真正驅動的地址了，然後去匹配DriverManager中已經註冊的Driver驅動，總有一款合適，否則就報錯了。
@Override
public Connection connect(String url, Properties properties) throws SQLException {
// if there is no url, we have problems
if (url == null) {
throw new SQLException("url is required");
}
if( !acceptsURL(url) ) {
return null;
}
// find the real driver for the URL
Driver passThru = findPassthru(url);
P6LogQuery.debug("this is " + this + " and passthru is " + passThru);
final long start = System.nanoTime();
if (P6SpyDriver.jdbcEventListenerFactory == null) {
P6SpyDriver.jdbcEventListenerFactory = JdbcEventListenerFactoryLoader.load();
}
final Connection conn;
final JdbcEventListener jdbcEventListener = P6SpyDriver.jdbcEventListenerFactory.createJdbcEventListener();
final ConnectionInformation connectionInformation = ConnectionInformation.fromDriver(passThru);
connectionInformation.setUrl(url);
jdbcEventListener.onBeforeGetConnection(connectionInformation);
try {
conn = passThru.connect(extractRealUrl(url), properties);
connectionInformation.setConnection(conn);
connectionInformation.setTimeToGetConnectionNs(System.nanoTime() - start);
jdbcEventListener.onAfterGetConnection(connectionInformation, null);
} catch (SQLException e) {
connectionInformation.setTimeToGetConnectionNs(System.nanoTime() - start);
jdbcEventListener.onAfterGetConnection(connectionInformation, e);
throw e;
}
return ConnectionWrapper.wrap(conn, jdbcEventListener, connectionInformation);
}4、拿到真正的驅動之後，先記錄它的相關資訊，然後根據真正驅動和它的資訊建立一個連線包裝器ConnectionWrapper（裝飾者模式：包裝器與被包裝者實現了相同的介面或者擁有著共同的父類，包裝器內部據有一個被包裝者的引用，包裝器在實現了介面或者重寫了父類的方法中，實際是呼叫了被包裝者的相同方法，只是在前後做一些處理。或者認為是靜態代理模式）。
5、連線包裝類ConnectionWrapper到底做了什麼呢？主要是對createStatement(...)方法和prepareStatement(...)方法得到的Statement和PreparedStatement也進行了包裝，類似ConnectionWrapper。
@Override
public Statement createStatement(int resultSetType, int resultSetConcurrency, int resultSetHoldability)
throws SQLException {
return StatementWrapper.wrap(
delegate.createStatement(resultSetType, resultSetConcurrency, resultSetHoldability),
new StatementInformation(connectionInformation), jdbcEventListener);
}
@Override
public PreparedStatement prepareStatement(String sql) throws SQLException {
return PreparedStatementWrapper.wrap(delegate.prepareStatement(sql),
new PreparedStatementInformation(connectionInformation, sql), jdbcEventListener);
}6、 StatementWrapper主要對執行語句的方法做了包裝，在前後利用監聽器觸發對應的處理邏輯（觀察者模式：當一個被觀察者或者叫釋出者發生了改變之後，執行其通知方法，所有實現了觀察者介面並且註冊了訂閱者身份的物件都會收到提醒，並進行各自的處理）。
7、其它包裝類ResultSetWrapper、CallableStatementWrapper等類似，在此不做過多解釋。
8、前面說到的監聽器，也就是觀察者模式。它們有一個介面JdbcEventListener，並提供了很多個實現類，其中有一個很特別的CompoundJdbcEventListener，它可以新增很多個其它單一功能的監聽器例項到自己內部集合裡，然後在呼叫介面方法時，分別執行其集合裡監聽器的對應方法。在包裝類或者其它地方呼叫監聽器的時候，預設是使用這個混合監聽器執行對應操作，這些操作在JdbcEventListener介面做了定義，並且不同實現類提供了不同的處理方式，裡面最常用的就是記錄日誌了。
9、具體會註冊哪些監聽器到CompoundJdbcEventListener的集合裡面，首先需要讀取配置資訊，然後會使用工廠模式建立對應的監聽器例項，最後加入到混合監聽器中。
總之，p6psy的核心思想是對具體廠商的驅動包裡面的幾個類做了包裝，在一些方法的前後增加了呼叫監聽器指定方法來對操作發生時做相應處理。
三、實現自己的SQL執行監控器
1、在讀懂了原始碼之後，就很容易對其進行改造了。它的包裝類、資訊類、監聽器介面和預設幾個實現類都做得很好，暫時沒有必要自己寫（得花很多時間和精力，費力不討好），直接拿過來就好。
2、如下，左邊是原來的類，很多吧（不過功能也非常多）；右邊是拷過來的核心類（自己寫的幾個也在裡面了）。
3、解決一下編譯問題，根據自己的情況做處理（不知道的話下載專案原始碼看一下，文章末尾會提供連結）。
4、下面就是自定義的功能了。
（1）首先，建立一個用於記錄SQL的執行情況的類，我將其命名為SimpleStatementInformation，主要是因為裡面的資訊基本都來自StatementInformation類。
/**
* 用於記錄SQL的執行情況
* @author z_hh
* @time 2018年11月23日
*/
public class SimpleStatementInformation implements Serializable {
private static final long serialVersionUID = 4104996496129361823L;
/** 執行結束時間 */
private Date execEndTime;
/** 編譯語句 */
private String sourceSql;
/** 執行語句 */
private String sqlWithValue;
/** 語句型別 */
private String type;
/** 是否成功 */
private Boolean success;
/** 耗時（毫秒） */
private Double timeElapsedMillis;
/** 錯誤資訊 */
private String errorMsg;
public SimpleStatementInformation() {
// TODO Auto-generated constructor stub
}
public SimpleStatementInformation(Date execEndTime, String sourceSql, String sqlWithValue, String type,
Boolean success, Double timeElapsedMillis, String errorMsg) {
super();
this.execEndTime = execEndTime;
this.sourceSql = sourceSql;
this.sqlWithValue = sqlWithValue;
this.type = type;
this.success = success;
this.timeElapsedMillis = timeElapsedMillis;
this.errorMsg = errorMsg;
}
// 省略getter、setter、toString方法
}（2）然後，實現一個自己的監聽器。這裡我選擇繼承SimpleJdbcEventListener類，因為現在只想記錄SQL語句執行後的資訊，所以只需重寫SimpleJdbcEventListener類擴充套件的onAfterAnyExecute、onAfterAnyAddBatch兩個方法即可。又因為兩個方法中做記錄的程式碼是一樣的，所以封裝了一個addRecore(...)方法。
/**
* This implementation of {@link JdbcEventListener} must always be applied as
* the first listener. It populates the information objects
* {@link StatementInformation}, {@link PreparedStatementInformation},
* {@link cn.zhh.sql_monitor.common.CallableStatementInformation} and
* {@link ResultSetInformation}
*/
public class MyEventListener extends SimpleJdbcEventListener {
public static final MyEventListener INSTANCE = new MyEventListener();
/**
* 執行緒安全，但是效率低。後續考慮使用concurrent包下的類
*/
private static final List<SimpleStatementInformation> SQLS = Collections.synchronizedList(new ArrayList<>());
public static List<SimpleStatementInformation> getSqls() {
return SQLS;
}
private MyEventListener() {
}
/**
* This callback method is executed after any {@link java.sql.Statement}.execute* method is invoked
*
* @param statementInformation The meta information about the {@link java.sql.Statement} being invoked
* @param timeElapsedNanos The execution time of the execute call
* @param e The {@link SQLException} which may be triggered by the call (<code>null</code> if
* there was no exception).
*/
@Override
public void onAfterAnyExecute(StatementInformation statementInformation, long timeElapsedNanos, SQLException e) {
addRecord(statementInformation, timeElapsedNanos, e);
}
/**
* This callback method is executed before any {@link java.sql.Statement}.addBatch* method is invoked
*
* @param statementInformation The meta information about the {@link java.sql.Statement} being invoked
* @param timeElapsedNanos The execution time of the execute call
* @param e The {@link SQLException} which may be triggered by the call (<code>null</code> if
* there was no exception).
*/
@Override
public void onAfterAnyAddBatch(StatementInformation statementInformation, long timeElapsedNanos, SQLException e) {
addRecord(statementInformation, timeElapsedNanos, e);
}
/**
* 記錄語句執行資訊
* @param statementInformation
* @param timeElapsedNanos
* @param e
*/
private void addRecord(StatementInformation statementInformation, long timeElapsedNanos, SQLException e) {
double timeElapsedMillis = timeElapsedNanos / 1000_000;
boolean success = Objects.isNull(e);
SimpleStatementInformation information = new SimpleStatementInformation(
new Date(),
statementInformation.getSql(),
statementInformation.getSqlWithValues(),
"Execute",
success,
timeElapsedMillis,
success ? null : e.getMessage());
SQLS.add(information);
}
}（3）接著，在JdbcEventListenerFactory類中createJdbcEventListener()方法裡面建立一個CompoundJdbcEventListener例項，並將預設的DefaultEventListener（記錄SQL執行時間的）、自己定義的MyEventListener加進去。
（4）最後，寫個測試來爽一下。
執行幾組語句，最後面將MyEventListener裡面的記錄打印出來。
/**
* 客戶端測試
* @author z_hh
* @time 2018年11月25日
*/
public class Client {
public static void main(String[] args) throws Exception {
String driver = "cn.zhh.sql_monitor2.spy.P6SpyDriver";
String url = "jdbc:p6spy:mysql://ip:3306/test?useUnicode=true&characterEncoding=UTF-8&allowMultiQueries=true";
String user = "root";
String password = "password";
Class.forName(driver);
String selectSql = "select name from student where id = 1";
String selectSqlForPrepare = "select address from student where id = ?";
String insertSqlForPrepare = "insert into student values(?, ?, 1, ?, ?, ?)";
String deleteSql = "delete from student where id = 3";
String deleteSqlForError = "delete from not_exist_table where id = 2";
try (Connection con = DriverManager.getConnection(url, user, password);
Statement statement = con.createStatement();
PreparedStatement preparedStatementSelect = con.prepareStatement(selectSqlForPrepare);
PreparedStatement preparedStatementInsert = con.prepareStatement(insertSqlForPrepare);
) {
// 1、查詢
ResultSet resultSet1 = statement.executeQuery(selectSql);
System.out.println("selectSql執行結果：" + (resultSet1.next() ? resultSet1.getString(1) : null));
// 2、預處理查詢
preparedStatementSelect.setInt(1, 4);
preparedStatementSelect.executeQuery();
ResultSet resultSet2 = preparedStatementSelect.executeQuery();
System.out.println("preparedStatementSelect執行結果：" + (resultSet2.next() ? resultSet1.getString(1) : null));
// 3、預處理插入
preparedStatementInsert.setInt(1, 6);
preparedStatementInsert.setString(2, "zhh");
preparedStatementInsert.setString(3, "13800138000");
preparedStatementInsert.setDate(4, new java.sql.Date(2018, 12, 31));
preparedStatementInsert.setString(5, "廣州市天河區");
boolean success1 = preparedStatementInsert.execute();
System.out.println("insertSqlForPrepare執行結果：" + success1);
// 4、刪除
boolean success2 = statement.execute(deleteSql);
System.out.println("deleteSql執行結果：" + success2);
// 5、不存在表的刪除
boolean success3 = statement.execute(deleteSqlForError);
} catch (Exception e) {
e.printStackTrace();
}
MyEventListener.getSqls().forEach(information -> {
System.out.println(information);
});
}
}12:44:55.029 [main] DEBUG cn.zhh.sql_monitor2.spy.P6SpyDriver - this is [email protected] and passthru is [email protected]
selectSql執行結果：zhh
preparedStatementSelect執行結果：zhh
insertSqlForPrepare執行結果：false
deleteSql執行結果：false
com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table 'test.not_exist_table' doesn't exist
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
at com.mysql.jdbc.Util.getInstance(Util.java:408)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:944)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3973)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3909)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2527)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2680)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2480)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2438)
at com.mysql.jdbc.StatementImpl.executeInternal(StatementImpl.java:845)
at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:745)
at cn.zhh.sql_monitor2.wrapper.StatementWrapper.execute(StatementWrapper.java:118)
at cn.zhh.sql_monitor2.Client.main(Client.java:53)
SimpleStatementInformation [
execEndTime=Sun Nov 25 12:44:55 CST 2018,
sourceSql=select name from student where id = 1,
sqlWithValue=select name from student where id = 1,
type=Execute,
success=true,
timeElapsedMillis=29.0,
errorMsg=null]
SimpleStatementInformation [
execEndTime=Sun Nov 25 12:44:55 CST 2018,
sourceSql=select address from student where id = ?,
sqlWithValue=select address from student where id = 4,
type=Execute,
success=true,
timeElapsedMillis=6.0,
errorMsg=null]
SimpleStatementInformation [
execEndTime=Sun Nov 25 12:44:55 CST 2018,
sourceSql=select address from student where id = ?,
sqlWithValue=select address from student where id = 4,
type=Execute,
success=true,
timeElapsedMillis=9.0,
errorMsg=null]
SimpleStatementInformation [
execEndTime=Sun Nov 25 12:44:55 CST 2018,
sourceSql=insert into student values(?, ?, 1, ?, ?, ?),
sqlWithValue=insert into student values(6, 'zhh', 1, '13800138000', '3919-01-31', '廣州市天河區'),
type=Execute,
success=true,
timeElapsedMillis=33.0,
errorMsg=null]
SimpleStatementInformation [
execEndTime=Sun Nov 25 12:44:55 CST 2018,
sourceSql=delete from student where id = 3,
sqlWithValue=delete from student where id = 3,
type=Execute,
success=true,
timeElapsedMillis=16.0,
errorMsg=null]
SimpleStatementInformation [
execEndTime=Sun Nov 25 12:44:55 CST 2018,
sourceSql=delete from not_exist_table where id = 2,
sqlWithValue=delete from not_exist_table where id = 2,
type=Execute,
success=false,
timeElapsedMillis=24.0,
errorMsg=Table 'test.not_exist_table' doesn't exist]
MyEventListener的處理邏輯僅做測試，ArrayList使用synchronized同步很影響效能，高併發下考慮ConcurrentHashMap或者非同步記錄。