這篇文章主要介紹怎么通過(guò)binlog輕松的找到?jīng)]有及時(shí)提交的事物，文中介紹的非常詳細(xì)，具有一定的參考價(jià)值，感興趣的小伙伴們一定要看完！
成都創(chuàng)新互聯(lián)公司堅(jiān)持“要么做到，要么別承諾”的工作理念，服務(wù)領(lǐng)域包括：網(wǎng)站制作、做網(wǎng)站、企業(yè)官網(wǎng)、英文網(wǎng)站、手機(jī)端網(wǎng)站、網(wǎng)站推廣等服務(wù)，滿(mǎn)足客戶(hù)于互聯(lián)網(wǎng)時(shí)代的諸城網(wǎng)站設(shè)計(jì)、移動(dòng)媒體設(shè)計(jì)的需求，幫助企業(yè)找到有效的互聯(lián)網(wǎng)解決方案。努力成為您成熟可靠的網(wǎng)絡(luò)建設(shè)合作伙伴！
以前我也寫(xiě)過(guò)一個(gè)幫助如下：
http://blog.itpub.net/7728585/viewspace-2133985/
但是沒(méi)有包含最新的對(duì)長(zhǎng)期不提交事物的查詢(xún)，因?yàn)檫@是我新加入的，這個(gè)功能會(huì)在本文描述
另外這里涉及到比較重要的兩個(gè)binlog event及另外這里涉及到比較重要的兩個(gè)binlog event及query event和xid event，參考的早期的文章
解析MySQL BINLOG 二進(jìn)制格式(3)--QUERY_EVENT
http://blog.itpub.net/7728585/viewspace-2133321/
解析MYSQL BINLOG 二進(jìn)制格式(7)--Xid_log_event/XID_EVENThttp://blog.itpub.net/7728585/viewspace-2133502/
當(dāng)然這是一個(gè)系列如果有興趣可以全部看看
http://blog.itpub.net/7728585/viewspace-2133188/ 解析MYSQL BINLOG 二進(jìn)制格式(1)--準(zhǔn)備工作 http://blog.itpub.net/7728585/viewspace-2133189/ 解析MYSQL BINLOG 二進(jìn)制格式(2)--FORMAT_DESCRIPTION_EVENT http://blog.itpub.net/7728585/viewspace-2133321/ 解析MYSQL BINLOG 二進(jìn)制格式(3)--QUERY_EVENT http://blog.itpub.net/7728585/viewspace-2133429/ 解析MYSQL BINLOG 二進(jìn)制格式(4)--TABLE_MAP_EVENT http://blog.itpub.net/7728585/viewspace-2133463/ 解析MYSQL BINLOG 二進(jìn)制格式(5)--WRITE_ROW_EVENT http://blog.itpub.net/7728585/viewspace-2133469/ 解析MYSQL BINLOG 二進(jìn)制格式(6)--UPDATE_ROW_EVENT/DELETE_ROW_EVENT http://blog.itpub.net/7728585/viewspace-2133502/ 解析MYSQL BINLOG 二進(jìn)制格式(7)--Xid_log_event/XID_EVENT http://blog.itpub.net/7728585/viewspace-2133506/ 解析MYSQL BINLOG二進(jìn)制格式(8)--GTID_LOG_EVENT/ANONYMOUS_GTID_LOG_EVENT及其他 http://blog.itpub.net/7728585/viewspace-2133534/ 解析MYSQL BINLOG二進(jìn)制格式(9)--infobin解析binlog幫助文檔 http://blog.itpub.net/7728585/viewspace-2133537/ 解析MYSQL BINLOG二進(jìn)制格式(10)--問(wèn)題解答
在innodb中如果我們顯示的開(kāi)啟和提交一個(gè)事物如下:
begin;
insert XXX;
update XXX;
select XXX;
commit;
這是一個(gè)我們熟知的事物，在MYSQL BINLOG 行格式中(當(dāng)然本工具也可以用于語(yǔ)句格式的binlog),
整個(gè)事物包含如下的event
GTID EVENT
--QUERY EVENT
----MAP EVENT
------WRITE EVENT(insert)
----MAP EVENT
------UPDATE_ROW_EVENT (update)
----(select 沒(méi)有binlog產(chǎn)生)
XID EVENT (commit)
在每一個(gè)event中的header中存在4字節(jié)的一個(gè)時(shí)間，這個(gè)時(shí)間是新紀(jì)元時(shí)間。
而這個(gè)時(shí)間來(lái)自于dispatch_command函數(shù)最開(kāi)始的設(shè)置線程的中的一個(gè)set_time()
函數(shù)
start_utime= utime_after_lock= my_micro_time();
當(dāng)發(fā)起commit命令后這個(gè)時(shí)間會(huì)記錄到XID EVENT中。那么我們得到一個(gè)設(shè)計(jì)思路
我們可以用XID EVENT的時(shí)間-QUERY EVENT的時(shí)間來(lái)得到一個(gè)時(shí)間差為事物持續(xù)的時(shí)間
，但是要注意如果不是手動(dòng)提交而是自動(dòng)提交當(dāng)然也就不存在沒(méi)有及時(shí)提交的事物了，
并且這里使用QUERY EVENT而沒(méi)有使用GTID EVENT是為了兼容5.6不開(kāi)啟GTID的情況，
在5.7中即使不開(kāi)啟GTID也會(huì)有匿名的GTID EVENT。
另外值得注意的一點(diǎn)就是即使一個(gè)事物持續(xù)時(shí)間很長(zhǎng)，并不一定是沒(méi)有及時(shí)提交，可能
事物中包含了select語(yǔ)句這種不記錄binlog的語(yǔ)句，這種是通過(guò)binlog無(wú)法確定的，但是
我們至少可以將這種長(zhǎng)時(shí)間未提交的事物中的DML語(yǔ)句找到交給開(kāi)發(fā)進(jìn)行分析到底是什么
原因。
此工具實(shí)際來(lái)自我早前學(xué)習(xí)binlog event的時(shí)候?qū)懙墓ぞ遡nfobin，這次由于線上出現(xiàn)了
大量未及時(shí)提交的事物，從而加入了新的功能。
本工具的幫助文檔在
http://blog.itpub.net/7728585/viewspace-2133985/
簡(jiǎn)單的說(shuō)本工具總共分為兩部分，分別叫做DETAIL和TOTAL
第一部分
通過(guò)分析原生的MYSQL BINLOG進(jìn)行逐條分析(常用的EVENT進(jìn)行分析)，這部分
叫做DETAIL部分
第二部分
通過(guò)掃描到數(shù)據(jù)根據(jù)用戶(hù)的輸入信息進(jìn)行匯總得到TOTAL部分，在TOTAL中會(huì)統(tǒng)計(jì)如下信息
Trx total[counts]: 總的事物個(gè)數(shù)
Event total[counts]: 總的event個(gè)數(shù)
Avg binlog size(/sec):平均每秒生成的binlog大小
Avg binlog size(/min):平均每分生成的binlog大小
--Piece view:
根據(jù)用戶(hù)指定piece大小得到一個(gè)高度均衡直方圖，這個(gè)直方圖用于發(fā)現(xiàn)是否有某個(gè)時(shí)間段生成binlog特別大
--Large than xxx(bytes) trx:
大于xxx BYTES的事物，最后會(huì)有一個(gè)匯總，這部分給出了大事物的開(kāi)始位置trx_begin_p結(jié)束的位置trx_end_p
--Large than xxx(secs) trx:
大于xxx 秒的事物都會(huì)進(jìn)行匯總，給出了開(kāi)始時(shí)間trx_begin_time,結(jié)束時(shí)間trx_end_time，開(kāi)始位置trx_query_pos
結(jié)束位置trx_xid_pos,這個(gè)功能是我新加的。
有了binlog的開(kāi)始和結(jié)束位置要找到是什么DML語(yǔ)句就非常方便了如下就可以了
./mysqlbinlog mysql-bin.000274 --base64-output='decode-rows' -vv --start-position=592514409 --stop-position=592515464|more
使用幫助
[dbadmin@bak ~]$ ./infobin [Author]: gaopeng [QQ]:22389860 [blog]:http://blog.itpub.net/7728585/ --USAGE:./infobin [binlogfile] [piece] [bigtrxsize] [bigtrxtime] [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))
使用方法
./infobin mysql-bin.000274 2 200000 400 > log1.log
mysql-bin.000274:binlog名字
2:分為多少piece來(lái)統(tǒng)計(jì)生成直方圖
200000:事物大小 大于約200K的事物進(jìn)行匯總
400:事物持續(xù)時(shí)間大于400秒的時(shí)間進(jìn)行匯總
本工具主要的意義包含4個(gè)方面
能夠更加清晰找到一個(gè)事物如下:
>Gtid Event:Pos:504(0X1f8) N_pos:569(0X239) Time:1496993578 Event_size:65(bytes) Gtid:89dfa8a4-cb13-11e6-b54-0c29a879a3:2 -->Query Event:Pos:569(0X239) N_Pos:641(0X281) Time:1496993578 Event_size:72(bytes) Exe_time:0 Use_db:test Statment(35b-trun):BEGIN /*!Trx begin!*/ Gno:2 ---->Map Event:Pos641(0X281) N_pos:689(0X2b1) Time:1496993578 Event_size:48(bytes) TABLE_ID:142 DB_NAME:test TABLE_NAME:test Gno:2 ------>Insert Event:Pos:689(0X2b1) N_pos:733(0X2dd) Time:1496993578 Event_size:44(bytes) Dml on table: test.test table_id:142 Gno:2 >Xid Event:Pos:733(0X2dd) N_Pos:764(0X2fc) Time:1496993578 Event_size:31(bytes) COMMIT; /*!Trx end*/ Gno:2
顯然這是一個(gè)事物
能夠通過(guò)直方圖判斷binlog什么時(shí)候生成量更大如下:
--Piece view: (1)Time:1487560299-1487560543(244(s)) piece:107374204(bytes)[104857.625(kb)] (2)Time:1487560543-1487560751(208(s)) piece:107374204(bytes)[104857.625(kb)] (3)Time:1487560751-1487561012(261(s)) piece:107374204(bytes)[104857.625(kb)] (4)Time:1487561012-1487561480(468(s)) piece:107374204(bytes)[104857.625(kb)] (5)Time:1487561480-1487562682(1202(s)) piece:107374204(bytes)[104857.625(kb)] (6)Time:1487562682-1487563492(810(s)) piece:107374204(bytes)[104857.625(kb)] (7)Time:1487563492-1487563723(231(s)) piece:107374204(bytes)[104857.625(kb)] (8)Time:1487563723-1487563951(228(s)) piece:107374204(bytes)[104857.625(kb)] (9)Time:1487563951-1487564159(208(s)) piece:107374204(bytes)[104857.625(kb)] (10)Time:1487564159-1487564409(250(s)) piece:107374204(bytes)[104857.625(kb)]
一目了然1487560543-1487560751和1487564159-1487564409生成的binlog更大(注意是新紀(jì)元時(shí)間)
可以更加清楚有本binlog有哪些大事物如下:
--Large than 700000(bytes) trx: (1)Trx_size:719621(bytes)[702.755(kb)] trx_begin_p:60579814[0X39C5FE6] trx_end_p:61299435[0X3A75AEB] (2)Trx_size:719771(bytes)[702.901(kb)] trx_begin_p:177760551[0XA986927] trx_end_p:178480322[0XAA364C2] (3)Trx_size:719779(bytes)[702.909(kb)] trx_begin_p:314334603[0X12BC5D8B] trx_end_p:315054382[0X12C7592E] (4)Trx_size:719803(bytes)[702.933(kb)] trx_begin_p:317542845[0X12ED51BD] trx_end_p:318262648[0X12F84D78]
大事物的意義不言而喻，因?yàn)樵诤瘮?shù)order_commit函數(shù)中其中的3個(gè)隊(duì)列FLUSH隊(duì)列、SYNC隊(duì)列、COMMIT隊(duì)列均是串行的
事物過(guò)大會(huì)堵塞全庫(kù)其他的事物提交(GROUP COMMIT)
可以更加清楚看到本binlog中有哪些未及時(shí)提交的事物如下:
--Large than 400(secs) trx: (1)Trx_sec:406(sec) trx_begin_time:1502441602 trx_end_time:1502442008 trx_query_pos:592514409 trx_xid_pos:592515464 query_exe_time:90 (2)Trx_sec:411(sec) trx_begin_time:1502441597 trx_end_time:1502442008 trx_query_pos:592518620 trx_xid_pos:592519666 query_exe_time:95 (3)Trx_sec:407(sec) trx_begin_time:1502441601 trx_end_time:1502442008 trx_query_pos:592528469 trx_xid_pos:592529524 query_exe_time:91 (4)Trx_sec:538(sec) trx_begin_time:1502441539 trx_end_time:1502442077 trx_query_pos:595102123 trx_xid_pos:595103178 query_exe_time:153 (5)Trx_sec:531(sec) trx_begin_time:1502441547 trx_end_time:1502442078 trx_query_pos:595141415 trx_xid_pos:595142470 query_exe_time:145 (6)Trx_sec:443(sec) trx_begin_time:1502441694 trx_end_time:1502442137 trx_query_pos:597451804 trx_xid_pos:597452859 query_exe_time:0 (7)Trx_sec:546(sec) trx_begin_time:1502441592 trx_end_time:1502442138 trx_query_pos:597531453 trx_xid_pos:597532508 query_exe_time:100 (8)Trx_sec:468(sec) trx_begin_time:1502441697 trx_end_time:1502442165 trx_query_pos:598471241 trx_xid_pos:598472296 query_exe_time:0 (9)Trx_sec:515(sec) trx_begin_time:1502441693 trx_end_time:1502442208 trx_query_pos:600613882 trx_xid_pos:600614928 query_exe_time:0
這也是本次新加入的功能。也是為查看長(zhǎng)期不提交事物定做的。
比如我做如下一個(gè)事物:
flush binary logs; begin; insert into testgp values(10); insert into testgp values(20); select sleep(5) from testgp limit 2; commit; flush binary logs;
輸出如下：
-------------Now begin-------------- Check Mysql Version is:5.7.13-log Check Mysql binlog format ver is:V4 Check This binlog is closed! Check This binlog total size:585(bytes) Note:load data infile not check! ------------Detail now-------------- >Format description log Event:Pos:4(0X4) N_pos:123(0X7b) Time:1502678321 Event_size:119(bytes) >Previous gtid Event:Pos:123(0X7b) N_pos:194(0Xc2) Time:1502678321 Event_size:71(bytes) >Gtid Event:Pos:194(0Xc2) N_pos:259(0X103) Time:1502678332 Event_size:65(bytes) Gtid:4a6f2a67-5d87-11e6-a6bd-0c29a879a3:196824 last_committed=0 sequence_number=1 -->Query Event:Pos:259(0X103) N_Pos:331(0X14b) Time:1502678322 Event_size:72(bytes) Exe_time:0 Use_db:test Statment(35b-trun):BEGIN /*!Trx begin!*/ Gno:196824 ---->Map Event:Pos331(0X14b) N_pos:380(0X17c) Time:1502678322 Event_size:49(bytes) TABLE_ID:294 DB_NAME:test TABLE_NAME:testgp Gno:196824 ------>Insert Event:Pos:380(0X17c) N_pos:420(0X1a4) Time:1502678322 Event_size:40(bytes) Dml on table: test.testgp table_id:294 Gno:196824 ---->Map Event:Pos420(0X1a4) N_pos:469(0X1d5) Time:1502678322 Event_size:49(bytes) TABLE_ID:294 DB_NAME:test TABLE_NAME:testgp Gno:196824 ------>Insert Event:Pos:469(0X1d5) N_pos:509(0X1fd) Time:1502678322 Event_size:40(bytes) Dml on table: test.testgp table_id:294 Gno:196824 >Xid Event:Pos:509(0X1fd) N_Pos:540(0X21c) Time:1502678332 Event_size:31(bytes) COMMIT; /*!Trx end*/ Gno:196824 >Rotate log Event:Pos:540(0X21c) N_pos:585(0X249) Time:1502678332 Event_size:45(bytes) -------------Total now-------------- Trx total[counts]:1 Event total[counts]:10 Max trx event size:119(bytes) Pos:4[0X4] Avg binlog size(/sec):53.182(bytes)[0.052(kb)] Avg binlog size(/min):3190.909(bytes)[3.116(kb)] --Piece view: (1)Time:1502678321-1502678321(0(s)) piece:117(bytes)[0.114(kb)] (2)Time:1502678321-1502678322(1(s)) piece:117(bytes)[0.114(kb)] (3)Time:1502678322-1502678322(0(s)) piece:117(bytes)[0.114(kb)] (4)Time:1502678322-1502678322(0(s)) piece:117(bytes)[0.114(kb)] (5)Time:1502678322-1502678332(10(s)) piece:117(bytes)[0.114(kb)] --Large than 200000(bytes) trx: No trx find! --Large than 8(secs) trx: (1)Trx_sec:10(sec) trx_begin_time:1502678322 trx_end_time:1502678332 trx_query_pos:259 trx_xid_pos:540 query_exe_time:0
這里我們看到了我們剛才做的沒(méi)有及時(shí)提交的事物
--Large than 8(secs) trx: (1)Trx_sec:10(sec) trx_begin_time:1502678322 trx_end_time:1502678332 trx_query_pos:259 trx_xid_pos:540 query_exe_time:0
起始和結(jié)束位置有了直接mysqlbinlog查吧！
以上是“怎么通過(guò)binlog輕松的找到?jīng)]有及時(shí)提交的事物”這篇文章的所有內(nèi)容，感謝各位的閱讀！希望分享的內(nèi)容對(duì)大家有幫助，更多相關(guān)知識(shí)，歡迎關(guān)注創(chuàng)新互聯(lián)行業(yè)資訊頻道！
重慶分公司
重慶分公司
