小編給大家分享一下如何巧用Event發(fā)現(xiàn)問題，相信大部分人都還不怎么了解，因此分享這篇文章給大家參考一下，希望大家閱讀完這篇文章后大有收獲，下面讓我們一起去了解一下吧！
在弋陽等地區(qū)，都構(gòu)建了全面的區(qū)域性戰(zhàn)略布局，加強發(fā)展的系統(tǒng)性、市場前瞻性、產(chǎn)品創(chuàng)新能力，以專注、極致的服務(wù)理念，為客戶提供成都網(wǎng)站設(shè)計、成都做網(wǎng)站 網(wǎng)站設(shè)計制作按需求定制開發(fā),公司網(wǎng)站建設(shè),企業(yè)網(wǎng)站建設(shè),品牌網(wǎng)站制作,成都營銷網(wǎng)站建設(shè),外貿(mào)網(wǎng)站制作,弋陽網(wǎng)站建設(shè)費用合理。
如果圖片不能顯示可查看下面鏈接：
https://www.jianshu.com/p/d636215d767f
有了前面對Event的了解，我們就可以利用這些Event來完成一些工作了。我曾經(jīng)在學(xué)習(xí)了這些常用的Event后，使用C語言寫過一個解析Event的工具，我叫它‘infobin’，意思就是從binary log提取信息的意思。據(jù)我所知雖然這個工具在少數(shù)情況下會出現(xiàn)BUG但是還是有些朋友在用。我這里并不是要推廣我的工具，而是要告訴大家這種思路。我是結(jié)合工作中遇到的一些問題來完成了這個工具的，主要功能包含如下：
分析binary log中是否有長期未提交的事務(wù) ，長期不提交的事務(wù)將會引發(fā)更多的鎖爭用。
分析binary log中是否有大事務(wù) ，大事務(wù)的提交可能會堵塞其它事務(wù)的提交。
分析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!!
接下來我們具體來看看這幾個功能大概是怎么實現(xiàn)的。
前面我已經(jīng)多次提到過對于一個手動提交的事務(wù)而言有如下特點，我們以‘Insert’語句為列：
GTID_LOG_EVENT和XID_EVENT是命令‘COMMIT’發(fā)起的時間。
QUERY_EVENT是第一個‘Insert’命令發(fā)起的時間。
MAP_EVENT/WRITE_ROWS_EVENT是每個‘Insert’命令發(fā)起的時間。
那實際上我們就可以用（1）減去（2）就能得到第一個‘DML’命令發(fā)起到‘COMMIT’命令發(fā)起之間所消耗的時間，再使用一個用戶輸入?yún)?shù)來自定義多久沒有提交的事務(wù)叫做長期未提交的事務(wù)就可以了，我的工具中使用bigtrxtime作為這個輸入。我們來用一個例子說明，我們做如下語句：
| 語句 | 時間 |
|---|---|
| begin | T1 |
| insert into testrr values(20); | 11:25:22 |
| insert into testrr values(30); | 11:25:26 |
| insert into testrr values(40); | 11:25:28 |
| commit; | 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的時間，那么這個事務(wù)從第一條語句開始到‘COMMIT’的時間就計算出來了。注意一點，實際上‘BEGIN’命令并沒有記錄到Event中，它只是做了一個標記讓事務(wù)不會自動進入提交流程，關(guān)于‘BEGIN’命令做了什么可以參考我的簡書文章如下：
https://www.jianshu.com/p/6de1e8071279
這部分實現(xiàn)比較簡單，我們只需要掃描每一個事務(wù)GTID_LOG_EVENT和XID_EVENT之間的所有Event將它們的總和計算下來，就可以得到每一個事務(wù)生成Event的大?。ǖ菫榱思嫒葑詈糜嬎鉗UERY_EVENT和XID_EVENT之間的Event總量）。再使用一個用戶輸入?yún)?shù)自定義多大的事務(wù)叫做大事務(wù)就可以了，我的工具中使用bigtrxsize作為這個輸入?yún)?shù)。
如果參數(shù)binlog_row_image參數(shù)設(shè)置為‘FULL’，我們可以大概計算一下特定表的每行數(shù)據(jù)修改生成的日志占用的大?。?/p>
‘Insert’和‘Delete’：因為只有before_image或者after_image，因此100字節(jié)一行數(shù)據(jù)加上一些額外的開銷大約加上10字節(jié)也就是110字節(jié)一行。如果定位大事務(wù)為100M那么大約修改量為100W行數(shù)據(jù)。
‘Update’：因為包含before_image和after_image，因此上面的計算的110字節(jié)還需要乘以2。因此如果定位大事務(wù)為100M那么大約修改量為50W行數(shù)據(jù)。
我認為20M作為大事務(wù)的定義比較合適，當然這個根據(jù)自己的需求進行計算。
這個實現(xiàn)就很簡單了，我們只需要把binary log按照輸入?yún)?shù)進行分片，統(tǒng)計結(jié)束Event和開始Event的時間差值就能大概算出每個分片生成花費了多久時間，我們工具使用piece作為分片的傳入?yún)?shù)。通過這個分析，我們可以大概知道哪一段時間Event生成量更大，也側(cè)面反映了數(shù)據(jù)庫的繁忙程度。
這個功能也非常實用，通過這個分析我們可以知道數(shù)據(jù)庫中哪一個表的修改量最大。實現(xiàn)方式主要是通過掃描binary log中的MAP_EVENT和接下來的DML Event，通過table id獲取表名，然后將DML Event的大小歸入這個表中，做一個鏈表，最后排序輸出就好了。但是前面我們說過table id即便在一個事務(wù)中也可能改變，這是我開始沒有考慮到的，因此這個工具有一定的問題，但是大部分情況是可以正常運行的。
下面我就來展示一下我說的這些功能，我做了如下操作：
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個事務(wù)：
刪除了tti表數(shù)據(jù)一共98304行數(shù)據(jù)。
向tti表插入了一條數(shù)據(jù)，等待了20多秒提交。
向tpp表插入了一條數(shù)據(jù)。
我們使用工具來分析一下，下面是統(tǒng)計輸出：
./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)
我們發(fā)現(xiàn)我們做的操作都統(tǒng)計出來了：
包含一個大事務(wù)日志總量大于500K，大小為800K左右，這是我的刪除tti表中98304行數(shù)據(jù)造成的。
--Large than 500000(bytes) trx: (1)Trx_size:888703(bytes)[867.874(kb)] trx_begin_p:299[0X12B] trx_end_p:889002[0XD90AA]
包含一個長期未提交的事務(wù)，時間為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)
好了到這里我想告訴你的就是，學(xué)習(xí)了Event過后就可以自己通過各種語言去試著解析binary log，也許你還能寫出更好的工具實現(xiàn)更多的功能。
當然也可以通過mysqlbinlog 進行解析后，然后通過shell/python去統(tǒng)計，但是這個工具的速度要遠遠快于這種方式。
以上是“如何巧用Event發(fā)現(xiàn)問題”這篇文章的所有內(nèi)容，感謝各位的閱讀！相信大家都有了一定的了解，希望分享的內(nèi)容對大家有所幫助，如果還想學(xué)習(xí)更多知識，歡迎關(guān)注創(chuàng)新互聯(lián)行業(yè)資訊頻道！
重慶分公司
重慶分公司
