追蹤MySQL中長時間運行的事務

接上一篇，未提交的事務致使鎖等待，鎖住一段時間後又提交了（也多是回滾），鎖釋放業務繼續運行。那麼咱們如何知道產生鎖的事務是在跑什麼SQL？

今天講的這個工具，就能夠經過監聽3306端口的數據，把每一個事務的起始時間，SQL命令都打印出來，並且能夠設置事務時長，好比事務時長超過10秒的。

參考連接：https://highdb.com/%E8%BF%BD%E8%B8%AAmysql%E4%B8%AD%E9%95%BF%E6%97%B6%E9%97%B4%E8%BF%90%E8%A1%8C%E7%9A%84%E4%BA%8B%E5%8A%A1/

github連接：https://github.com/yoshinorim/MySlowTranCapture,下載後解壓

---

#安裝

How to use:
* Install libpcap, libpcap-devel, boost, and boost-devel if not installed
* make
* make install
* Run myslowtrancapture

#運行

[root@xxxx MySlowTranCapture-master]# myslowtrancapture -f "tcp port 3306"
Monitoring any interface..
Filtering rule: tcp port 3306
Logging transactions that take more than 4000 milliseconds..
 ........開始等待符合條件的輸出

#默認檢測事務時長是4秒，咱們構造一個顯式事務，持續時間5秒，看看輸出結果

#MYSQL SESSION
mysql> select * from t1;
+------+
| id   |
+------+
|    3 |
|    4 |
+------+
2 rows in set (0.00 sec)

mysql> begin;delete from t1 where id=3;select sleep(5);rollback;
Query OK, 0 rows affected (0.00 sec)

Query OK, 1 row affected (0.00 sec)

+----------+
| sleep(5) |
+----------+
|        0 |
+----------+
1 row in set (5.00 sec)

Query OK, 0 rows affected (0.00 sec)

mysql> 

From 10.3.171.21:55871
2017/02/27 11:25:18.679918 ->
begin                         #事務開始
2017/02/27 11:25:18.679992 <-
GOT_OK 
2017/02/27 11:25:18.679995 <-
GOT_OK 
2017/02/27 11:25:18.680104 ->
delete from t1 where id=3     #這裏看到了事務SQL
2017/02/27 11:25:18.680336 <-
GOT_OK 
2017/02/27 11:25:18.680342 <-
GOT_OK 
2017/02/27 11:25:18.680477 ->
select sleep(5) 
2017/02/27 11:25:23.680669 <-
GOT_RES 
2017/02/27 11:25:23.680677 <-
GOT_RES 
2017/02/27 11:25:23.680973 ->
rollback                      #事務回滾

#事務時長=11:25:23-11:25:18=5秒

 除了rollback,commit以外，給當前session設置autocommit=0/1,也會提交當前事務-------這句話有問題，單獨開事務測試並無提交，在這裏看日誌又像是事務終止了，須要再調查下。

From 10.3.171.21:46378
2017/02/27 12:33:37.484762 ->
begin
2017/02/27 12:33:37.484806 <-
GOT_OK
2017/02/27 12:33:37.484808 <-
GOT_OK
2017/02/27 12:33:37.484958 ->
delete from test
2017/02/27 12:33:37.485061 <-
GOT_OK
2017/02/27 12:33:37.485063 <-
GOT_OK
2017/02/27 12:33:37.485167 ->
select sleep(200)
2017/02/27 12:36:57.485276 <-
GOT_RES
2017/02/27 12:36:57.485279 <-
GOT_RES
2017/02/27 12:36:57.485442 ->
TRAN_END BY set autocommit=0     #set autocommit=0

From 10.3.139.151:6610

產生上面輸出的SQL是這樣的：

mysql> begin;delete from test;select sleep(200);set autocommit=0;
Query OK, 0 rows affected (0.00 sec)

Query OK, 5 rows affected (0.00 sec)

+------------+
| sleep(200) |
+------------+
|          0 |
+------------+
1 row in set (3 min 19.98 sec)

Query OK, 0 rows affected (0.00 sec)

mysql>