共計 6228 個字符,預計需要花費 16 分鐘才能閱讀完成。
丸趣 TV 小編給大家分享一下如何巧用 Event 發現問題,相信大部分人都還不怎么了解,因此分享這篇文章給大家參考一下,希望大家閱讀完這篇文章后大有收獲,下面讓我們一起去了解一下吧!
如果圖片不能顯示可查看下面鏈接:
https://www.jianshu.com/p/d636215d767f
有了前面對 Event 的了解,我們就可以利用這些 Event 來完成一些工作了。我曾經在學習了這些常用的 Event 后,使用 C 語言寫過一個解析 Event 的工具,我叫它‘infobin’,意思就是從 binary log 提取信息的意思。據我所知雖然這個工具在少數情況下會出現 BUG 但是還是有些朋友在用。我這里并不是要推廣我的工具,而是要告訴大家這種思路。我是結合工作中遇到的一些問題來完成了這個工具的,主要功能包含如下:
分析 binary log 中是否有長期未提交的事務,長期不提交的事務將會引發更多的鎖爭用。
分析 binary log 中是否有大事務,大事務的提交可能會堵塞其它事務的提交。
分析 binary log 中每個表生成了多少 DML Event,這樣就能知道哪個表的修改量最大。
分析 binary log 中 Event 的生成速度,這樣就能知道哪個時間段生成的 Event 更多。
這個工具的幫助信息如下:
[root@gp1 infobin]# ./infobin
USAGE ERROR!
[Author]: gaopeng [QQ]:22389860 [blog]:http://blog.itpub.net/7728585/
--USAGE:./infobin binlogfile pieces bigtrxsize bigtrxtime [-t] [-force]
[binlogfile]:binlog file!
[piece]:how many piece will split,is a Highly balanced histogram,
find which time generate biggest binlog.(must:piece 2000000)
[bigtrxsize](bytes):larger than this size trx will view.(must:trx 256(bytes))
[bigtrxtime](sec):larger than this sec trx will view.(must: 0(sec))
[[-t]]:if [-t] no detail is print out,the result will small
[[-force]]:force analyze if unkown error check!!
接下來我們具體來看看這幾個功能大概是怎么實現的。
一、分析長期未提交的事務
前面我已經多次提到過對于一個手動提交的事務而言有如下特點,我們以‘Insert’語句為列:
GTID_LOG_EVENT 和 XID_EVENT 是命令‘COMMIT’發起的時間。
QUERY_EVENT 是第一個‘Insert’命令發起的時間。
MAP_EVENT/WRITE_ROWS_EVENT 是每個‘Insert’命令發起的時間。
那實際上我們就可以用(1)減去(2)就能得到第一個‘DML’命令發起到‘COMMIT’命令發起之間所消耗的時間,再使用一個用戶輸入參數來自定義多久沒有提交的事務叫做長期未提交的事務就可以了,我的工具中使用 bigtrxtime 作為這個輸入。我們來用一個例子說明,我們做如下語句:
語句時間 beginT1insert into testrr values(20);11:25:22insert into testrr values(30);11:25:26insert into testrr values(40);11:25:28commit;11:25:30
我們來看看 Event 的順序和時間如下:
|Event| 時間 |
|—-|—-|
|GTID_LOG_EVENT|11:25:30|
|QUERY_EVENT|11:25:22|
|MAP_EVENT(第 1 個 insert)|11:25:22|
|WRITE_ROWS_EVENT(第 1 個 insert)|11:25:22|
|MAP_EVENT(第 2 個 insert)|11:25:26|
|WRITE_ROWS_EVENT(第 2 個 insert)|11:25:26|
|MAP_EVENT(第 3 個 insert)|11:25:28|
|WRITE_ROWS_EVENT(第 3 個 insert)|11:25:28|
|XID_EVENT|11:25:30|
如果我們使用最后一個 XID_EVENT 的時間減去 QUERY_EVENT 的時間,那么這個事務從第一條語句開始到‘COMMIT’的時間就計算出來了。注意一點,實際上‘BEGIN’命令并沒有記錄到 Event 中,它只是做了一個標記讓事務不會自動進入提交流程,關于‘BEGIN’命令做了什么可以參考我的簡書文章如下:
https://www.jianshu.com/p/6de1e8071279
二、分析大事務
這部分實現比較簡單,我們只需要掃描每一個事務 GTID_LOG_EVENT 和 XID_EVENT 之間的所有 Event 將它們的總和計算下來,就可以得到每一個事務生成 Event 的大?。ǖ菫榱思嫒葑詈糜嬎?QUERY_EVENT 和 XID_EVENT 之間的 Event 總量)。再使用一個用戶輸入參數自定義多大的事務叫做大事務就可以了,我的工具中使用 bigtrxsize 作為這個輸入參數。
如果參數 binlog_row_image 參數設置為‘FULL’,我們可以大概計算一下特定表的每行數據修改生成的日志占用的大?。?/p>
‘Insert’和‘Delete’:因為只有 before_image 或者 after_image,因此 100 字節一行數據加上一些額外的開銷大約加上 10 字節也就是 110 字節一行。如果定位大事務為 100M 那么大約修改量為 100W 行數據。
‘Update’:因為包含 before_image 和 after_image,因此上面的計算的 110 字節還需要乘以 2。因此如果定位大事務為 100M 那么大約修改量為 50W 行數據。
我認為 20M 作為大事務的定義比較合適,當然這個根據自己的需求進行計算。
三、分析 binary log 中 Event 的生成速度
這個實現就很簡單了,我們只需要把 binary log 按照輸入參數進行分片,統計結束 Event 和開始 Event 的時間差值就能大概算出每個分片生成花費了多久時間,我們工具使用 piece 作為分片的傳入參數。通過這個分析,我們可以大概知道哪一段時間 Event 生成量更大,也側面反映了數據庫的繁忙程度。
四、分析每個表生成了多少 DML Event
這個功能也非常實用,通過這個分析我們可以知道數據庫中哪一個表的修改量最大。實現方式主要是通過掃描 binary log 中的 MAP_EVENT 和接下來的 DML Event,通過 table id 獲取表名,然后將 DML Event 的大小歸入這個表中,做一個鏈表,最后排序輸出就好了。但是前面我們說過 table id 即便在一個事務中也可能改變,這是我開始沒有考慮到的,因此這個工具有一定的問題,但是大部分情況是可以正常運行的。
五、工具展示
下面我就來展示一下我說的這些功能,我做了如下操作:
mysql flush binary logs;
Query OK, 0 rows affected (0.51 sec)
mysql select count(*) from tti;
+----------+
| count(*) |
+----------+
| 98304 |
+----------+
1 row in set (0.06 sec)
mysql delete from tti;
Query OK, 98304 rows affected (2.47 sec)
mysql begin;
Query OK, 0 rows affected (0.00 sec)
mysql insert into tti values(1, gaopeng
Query OK, 1 row affected (0.00 sec)
mysql select sleep(20);
+-----------+
| sleep(20) |
+-----------+
| 0 |
+-----------+
1 row in set (20.03 sec)
mysql commit;
Query OK, 0 rows affected (0.22 sec)
mysql insert into tpp values(10);
Query OK, 1 row affected (0.14 sec)
在示例中我切換了一個 binary log,同時做了 3 個事務:
刪除了 tti 表數據一共 98304 行數據。
向 tti 表插入了一條數據,等待了 20 多秒提交。
向 tpp 表插入了一條數據。
我們使用工具來分析一下,下面是統計輸出:
./infobin mysql-bin.000005 3 1000000 15 -t log.log
more log.log
-------------Total now--------------
Trx total[counts]:3
Event total[counts]:125
Max trx event size:8207(bytes) Pos:420[0X1A4]
Avg binlog size(/sec):9265.844(bytes)[9.049(kb)]
Avg binlog size(/min):555950.625(bytes)[542.921(kb)]
--Piece view:
(1)Time:1561442359-1561442383(24(s)) piece:296507(bytes)[289.558(kb)]
(2)Time:1561442383-1561442383(0(s)) piece:296507(bytes)[289.558(kb)]
(3)Time:1561442383-1561442455(72(s)) piece:296507(bytes)[289.558(kb)]
--Large than 500000(bytes) trx:
(1)Trx_size:888703(bytes)[867.874(kb)] trx_begin_p:299[0X12B]
trx_end_p:889002[0XD90AA]
Total large trx count size(kb):#867.874(kb)
--Large than 15(secs) trx:
(1)Trx_sec:31(sec) trx_begin_time:[20190625 14:00:08(CST)]
trx_end_time:[20190625 14:00:39(CST)] trx_begin_pos:889067
trx_end_pos:889267 query_exe_time:0
--Every Table binlog size(bytes) and times:
Note:size unit is bytes
---(1)Current Table:test.tpp::
Insert:binlog size(40(Bytes)) times(1)
Update:binlog size(0(Bytes)) times(0)
Delete:binlog size(0(Bytes)) times(0)
Total:binlog size(40(Bytes)) times(1)
---(2)Current Table:test.tti::
Insert:binlog size(48(Bytes)) times(1)
Update:binlog size(0(Bytes)) times(0)
Delete:binlog size(888551(Bytes)) times(109)
Total:binlog size(888599(Bytes)) times(110)
---Total binlog dml event size:888639(Bytes) times(111)
我們發現我們做的操作都統計出來了:
包含一個大事務日志總量大于 500K,大小為 800K 左右,這是我的刪除 tti 表中 98304 行數據造成的。
--Large than 500000(bytes) trx:
(1)Trx_size:888703(bytes)[867.874(kb)] trx_begin_p:299[0X12B]
trx_end_p:889002[0XD90AA]
包含一個長期未提交的事務,時間為 31 秒,這是我特意等待 20 多秒提交引起的。
--Large than 15(secs) trx:
(1)Trx_sec:31(sec) trx_begin_time:[20190625 14:00:08(CST)]
trx_end_time:[20190625 14:00:39(CST)] trx_begin_pos:889067
trx_end_pos:889267 query_exe_time:0
本 binary log 有兩個表的修改記錄 tti 和 tpp,其中 tti 表有‘Delete’操作和‘Insert’操作,tpp 表只有‘Insert’操作,并且包含了日志量的大小。
--Every Table binlog size(bytes) and times:
Note:size unit is bytes
---(1)Current Table:test.tpp::
Insert:binlog size(40(Bytes)) times(1)
Update:binlog size(0(Bytes)) times(0)
Delete:binlog size(0(Bytes)) times(0)
Total:binlog size(40(Bytes)) times(1)
---(2)Current Table:test.tti::
Insert:binlog size(48(Bytes)) times(1)
Update:binlog size(0(Bytes)) times(0)
Delete:binlog size(888551(Bytes)) times(109)
Total:binlog size(888599(Bytes)) times(110)
---Total binlog dml event size:888639(Bytes) times(111)
好了到這里我想告訴你的就是,學習了 Event 過后就可以自己通過各種語言去試著解析 binary log,也許你還能寫出更好的工具實現更多的功能。
當然也可以通過 mysqlbinlog 進行解析后,然后通過 shell/python 去統計,但是這個工具的速度要遠遠快于這種方式。
以上是“如何巧用 Event 發現問題”這篇文章的所有內容,感謝各位的閱讀!相信大家都有了一定的了解,希望分享的內容對大家有所幫助,如果還想學習更多知識,歡迎關注丸趣 TV 行業資訊頻道!