binlog二进制文件解析
本文主要介紹MySQL的binlog二進制文件的解析,目的是更好的了解binlog文件的構成并做相應的二次開發,并幫助對主從復制機制有更多理解。
以下內容基于row的日志格式。操作系統redhat7,MySQL版本5.7.17,開啟GTID。
?
一 Binlog生成
在MySQL中執行flush logs,并執行以下操作。
mysql> create database abcd; Query OK, 1 row affected (0.01 sec)mysql> create table test (a1 int primary key not null auto_increment, a2 double not null, a3 timestamp, a4 datetime, a5 char(10), a6 varchar(4000), a7 text); Query OK, 0 rows affected (0.21 sec)mysql> insert into test values(1, 2.222222222, now(), now(), 'abc', 'abcdefghasdasdasd', 'qwetrhyokxocm3479thcms9q25hdr9ker8thcfisdrhoc'); Query OK, 1 row affected (0.08 sec)mysql> update test set a1=10, a2=3.33333, a3=now(), a4=now(), a5='abcde', a6='a', a7='s' where a1=1; Query OK, 1 row affected (0.06 sec) Rows matched:1? Changed: 1? Warnings: 0mysql> delete from test; Query OK, 1 row affected (0.04 sec)mysql> drop table test; Query OK, 0 rows affected (0.22 sec)mysql> flush logs; Query OK, 0 rows affected (0.17 sec)可以得到文件 mysql-bin.000006
hexdump –C mysql-bin.000006
生成十六進制的解析文件。文件較長,之后會逐層分析。
?
二 Binlog文件構成
對于該binlog而言,主要包括以下幾種event。
- FORMAT_DESCRIPTION_EVENT
- GTID_LOG_EVENT/ANONYMOUS_GTID_LOG_EVENT
- QUERY_EVENT
- TABLE_MAP_EVENT
- WRITE_ROW_EVENT/UPDATE_ROW_EVENT/DELETE_ROW_EVENT
- XID_EVENT
- ROTATE_EVENT
除這些外還有許多其他類型event,但多數不常見或隨著binlog版本的升級而棄用。
每個event包括Binlog event header,Post-Header和Body三部分。
其中對于所有event而言,Binlog event header的長度與格式是相同的,之后會在
FORMAT_DESCRIPTION_EVENT部分做統一介紹。
Post-Header對于同類型的event是長度相同的,部分類型的event并沒有Post-Header。
Body則為event中的變量部分,主要表示Query event中的變量部分。
下面將詳細介紹每一種event在binlog中的解析方式。
?
三 FORMAT_DESCRIPTION_EVENT
該部分位于整個文件的頭部,每個binlog文件都必定會有唯一一個該event。
二進制文件內容
解析的binlog /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #180321 18:00:32 server id 1813309? end_log_pos 123 CRC32 0x77f16c93? Start: binlog v 4, server v 5.7.17-log created 180321 18:00:32 BINLOG ' QC2yWg89qxsAdwAAAHsAAAAAAAQANS43LjE3LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA AZNs8Xc= '/*!*/;Binlog event header部分:
fe 62 69 6e:文件前四位非Binlog event header部分,而是magic number,在這里指代.bin,代表文件的格式。
后面的Header總長固定為19個字節。
40 2d b2 5a:事件發生的時間戳。應用服務器是X86架構,在存儲的時候為小端模式,即低位字節排放在內存的低地址端,也即實際是5a b2 2d 40代表一個數值,解析成時間為2018/3/21 18:00:32。請務必注意,后面的絕大部分數值的表示都將是這樣反向的。
0f:type_code,代表該事件的類型,幾個重要的事件類型為:
- 0x02 QUERY_EVENT
- 0x04 ROTATE_EVENT
- 0x0f FORMAT_DESCRIPTION_EVENT
- 0x10 XID_EVENT
- 0x13 TABLE_MAP_EVENT
- 0x1d ROWS_QUERY_EVENT
- 0x1e WRITE_ROWS_EVENTv2
- 0x1f UPDATE_ROWS_EVENTv2
- 0x20 DELETE_ROWS_EVENTv2
- 0x21 GTID_EVENT
- 0x22 ANONYMOUS_GTID_EVENT
- 0x23 PREVIOUS_GTIDS_EVENT
3d ab 1b 00:server_id,就是MySQL配置cnf文件中的server_id。這里是00 1b ab 3d,代表1813309。
77 00 00 00:代表整個event的長度,長度為119。
7b 00 00 00:下一個event開始的位置,可以看到與前一個值剛好差4,也就是魔數的長度。
00 00:flags,每個events中flags代表的意義大致相同。在此處 00 00 代表binlog已經關閉, 00 01代表binlog仍開啟,具體詳見https://dev.mysql.com/doc/internals/en/binlog-event-flag.html。
以上便是所有event的Binlog event header的固定形式,之后便不再解析。
Post-Header 對于每一類型的event都是相同的。
FORMAT_DESCRIPTION_EVENT有Post-Header,并沒有Body部分,因為并沒有變量。
04 00:binlog的版本,mysql從5.0后日志都是v4版本的。
之后50位代表mysql-server的版本,5.7.17-log。在此處存的是字符串所以不須反過來看。
00 00 00 00:代表create timestamp,官網上解釋為seconds since Unix epoch when the binlog was created。
13:代表Binlog event heade的長度,固定長度是19。
之后39位代表了39種類型事件的Post-Header的長度,從0x01開始,與上面所介紹的時間類型是對應的。其中FORMAT_DESCRIPTION_EVENT為0x0f,即長度對應5f。
詳細的關系在 https://dev.mysql.com/doc/internals/en/format-description-event.html 上有部分的對應,雖然不全但是可以對應主要的event的Post-Header長度。
可以看到WRITE_ROWS_EVENT、UPDATE_ROWS_EVENT、DELETE_ROWS_EVENT這三種主要event長度都是0x0a,因為他們同屬于ROWS_EVENT。
后面四種可以在源碼中查到,分別為
TRANSACTION_CONTEXT_HEADER_LEN,VIEW_CHANGE_HEADER_LEN,XA_PREPARE_HEADER_LEN,ROWS_HEADER_LEN_V2。
93 6c f1 77:最后四位為循環冗余校驗碼,與解析出的CRC32 0x77f16c93是一致的。注意,每一個event末尾都會有這樣四個字節,之后也不再贅述。
?
四 PREVIOUS_GTIDS_EVENT
# at 123
#180321 18:00:32 server id 1813309? end_log_pos 194 CRC32 0xfeb5737a? Previous-GTIDs
# c5f7f863-1b95-11e8-9e24-0024e8629bab:1-4
Event type是23,緊接著FORMAT_DESCRIPTION_EVENT。
這個也是單個binlog文件中唯一的event,無論是否開關GTID都存在的。主要用來表示上一個binlog的最后一個GTID的位置。
Binlog event header中與前面解析唯一不同之處為flags的值是80,代表LOG_EVENT_IGNORABLE_F,在8.0官網寫著是代表這事件可以被忽略 (emm..
該event只有Body變量部分,沒有Post-Header,這個的解析官網和源碼上給的都不清晰,只能暫且做簡單的判斷。
c5 f7 f8 63 1b 95 11 e8 9e 24?00 24 e8 62 9b ab:中間十六字節代表server_uuid。
05 00 00 00 00 00 00 00:最后8位代表最新的GTID的編號。
?
五 GTID_EVENT/ANONYMOUS_GTID_EVENT
# at 194
#180321 18:00:45 server id 1813309? end_log_pos 259 CRC32 0x606aa948? GTID last_committed=0 sequence_number=1
SET @@SESSION.GTID_NEXT= 'c5f7f863-1b95-11e8-9e24-0024e8629bab:5'/*!*/;
event type是21,即GTID_EVENT。如果沒有開啟GTID模式,事件類型會是ANONYMOUS_GTID_EVENT,這兩個都屬于Gtid_log_event。
01:commit flag,代表事務提交情況。
c5 f7 f8 63 1b 95 11 e8 9e 24 00 24 e8 62 9b ab:server_uuid
05 00 00 00 00 00 00 00:該GTID號,與上文相同。
02:TS_TYPE,官網解釋 TS_TYPE is from {G_COMMIT_TS2} singleton set of values。
00 00 00 00 00 00 00 00:代表last_committed號 0
01 00 00 00 00 00 00 00:代表sequence_number號 1。
每一個Query事務前都會有這樣的一個GTID_EVENT,如果未開啟則是ANONYMOUS_GTID_EVENT。
其中ANONYMOUS_GTID_EVENT只有last_committed和sequence_number號,因為沒有GTID號生成因此其他位皆為0。
?
六 QUERY_EVENT
SET TIMESTAMP=1521626445/*!*/; SET @@session.pseudo_thread_id=95906/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1437073442/*!*/; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; /*!\C utf8mb4 *//*!*/; SET @@session.character_set_client=45,@@session.collation_connection=45,@@session.collation_server=45/*!*/; SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/; create database abcd /*!*/;# at 353
#180321 18:04:24 server id 1813309? end_log_pos 418 CRC32 0x8f20b94b? GTID last_committed=1 sequence_number=2
在row格式的binlog中,所有的建庫建表操作都是QUERY_EVENT。此處取出較短的建庫操作做分析,建表操作與建庫的binlog格式是完全相同的。
Post-Header的長度為0x0d。
00 01 76 a2:slave_proxy_id,代指一個用于臨時表的進程號,為了避免創建臨時表時重復。
00 00 00 00:表示語句執行時間,單位為秒。
04 :代表當前數據庫名字的長度,在這里為abcd。
00 00 :兩位錯誤碼,若非0則代表有誤,如果從庫在復制時收到錯誤碼將停止復制進程。
00 21 :v4新特性,為status_vars的長度,這個之后會有介紹。
Body的長度根據DDL語句的長度而定。
注意,此處的數據解析并不是連續不斷的形式,而是類似于key-value的形式,即一個單字節鍵名,對應數個字節的值。
00 00 00 00 00:鍵是00 代表Q_FLAGS2_CODE,以下是對應關系詳情
- 0x00004000 OPTION_AUTO_IS_NULL SQL_AUTO_IS_NULL
- 0x00080000 OPTION_NOT_AUTOCOMMIT FOREIGN_KEY_CHECKS
- 0x04000000 OPTION_NO_FOREIGN_KEY_CHECKS UNIQUE_CHECKS
- 0x08000000 OPTION_RELAXED_UNIQUE_CHECKS AUTOCOMMIT
每一項都屬于疊加的形式,即0x00084000 代表數據庫有前兩項屬性,之后的情況類似。
此處值為00 00 00 00,即不滿足上述條件。
01 22 00 a8 55 00 00 00 00:鍵是01 代表Q_SQL_MODE_CODE,值為 00 00 00 00 55 a8 00 22。具體的轉換內容詳見https://dev.mysql.com/doc/internals/en/query-event.html#q-flags2-code。在這里代表sql_mode的配置,跟上面一樣都屬于疊加的模式。
通過文檔可以解析出sql_mode為
PIPES_AS_CONCAT,ONLY_FULL_GROUP_BY,NO_AUTO_VALUE_ON_ZERO,STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION。
06 03 73 74 64:鍵是06 代表Q_CATALOG_NZ_CODE,值為 03 73 74 64
03代表字符串長度,73 74 64指代std字符串。
04 2d 00 2d 00 2d 00:鍵是04 代表Q_CHARSET_CODE,后面為三個雙字節數字,都為0x002d。分別是指@session.character_set_client=45,@@session.collation_connection=45,@@session.collation_server=45。
0c 01 61 62 63 64 00:鍵是0x0c 代表Q_UPDATED_DB_NAMES,后面跟為單字節的01,代表存儲訪問數據從庫的總數,測試環境中僅有一個從庫。之后跟的便是對應的數據庫的名稱,61 62 63 64對應abcd庫名,其中字符串需要以00來結尾字符串。
建表的QUERY_EVENT與建庫時一致的,大家可以手動分析下。
?
七 TABLE_MAP_EVENT
SET TIMESTAMP=1521626714/*!*/; SET @@session.time_zone='SYSTEM'/*!*/; BEGIN /*!*/;# at 782
#180321 18:05:14 server id 1813309? end_log_pos 843 CRC32 0x98b87aed? Table_map: `abcd`.`test` mapped to number 224
每個DML事務之前,都會有一個TABLE_MAP_EVENT,記錄操作對應的表的信息。
Post-Header的長度為0x08。
e0 00 00 00 00 00:代表庫的ID 224。
01 00 :保留位數,Reserved for future use。
Body部分:
04:庫名的長度,之后是庫名的字符串61 62 63 64 00 abcd,與上文相同。
04:表名的長度,和對應的表名74 65 73 74 00 test。
07:代表字段的個數,我們建表時設立了7種不同類型的字段。
可以看出,binlog是完全不記錄表的字段名稱的,只記錄對應的編號和類型。
讓我們重新看一下建表的內容。
create table test (a1 int primary key not null auto_increment, a2 double not null, a3 timestamp, a4 datetime, a5 char(10), a6 varchar(4000), a7 text);
03 05 11 12 fe 0f fc 08 08 00 00 fe 28 80 3e 02 78
其中每個字節都有對應的含義。
03代表MYSQL_TYPE_LONG。
05代表MYSQL_TYPE_DOUBLE,后面會跟一位metadata。
11代表MYSQL_TYPE_TIME,這個官網寫后面沒有metadata,但是其實是有一個00站位的,而且跟是否有默認值無關。
12代表MYSQL_TYPE_DATETIME,跟MYSQL_TYPE_TIME情況相同。
Fe代表MYSQL_TYPE_STRING,后面會跟兩位metadata
0f代表MYSQL_TYPE_VARCHAR,后面會跟兩位metadata
Fc代表MYSQL_TYPE_BLOB,后面會跟一位metadata
之后的08代表metadata length:08 00 00 fe 28 80 3e 02
首先08對應的MYSQL_TYPE_DOUBLE的metadata,代表sizeof(double),也就是8
之后00 00就跟上文說的一樣,是MYSQL_TYPE_TIME和MYSQL_TYPE_DATETIME的metadata。
fe 28:在之后的insert語句的binlog中,可以看到有@5='abc' /* STRING(40) meta=65064 nullable=1 is_null=0 */的內容,其中的meta值便是0xfe28。
80 3e: 與第六列中@6='abcdefghasdasdasd' /* VARSTRING(16000) meta=16000 nullable=1 is_null=0 */中的meta值一致。
02:與第七列中@7='qwetrhyokxocm3479thcms9q25hdr9ker8thcfisdrhoc' /* BLOB/TEXT meta=2 nullable=1 is_null=0 */中的meta值一致。
78這一字節比較特殊,我們需要把它拆為01111000,后七位分別對應表的七個字段,其中1代表非空,0代表可為空。如果表的字段個數超過8的話就會多字節來表示。
詳細的對應關系可以到
https://dev.mysql.com/doc/dev/mysql-server/8.0.0/classbinary__log_1_1Table__map__event.html
上查看。
?
八 WRITE_ROW_EVENT/DELETE_ROW_EVENT
# at 843
#180321 18:05:14 server id 1813309? end_log_pos 970 CRC32 0x6c6819d3? Write_rows: table id 224 flags: STMT_END_F
MYSQL_TYPE_LONG
BINLOG '
Wi6yWhM9qxsAPQAAAEsDAAAAAOAAAAAAAAEABGFiY2QABHRlc3QABwMFERL+D/wICAAA/iiAPgJ4
7Xq4mA==
Wi6yWh49qxsAfwAAAMoDAAAAAOAAAAAAAAEAAgAH/4ABAAAAwnm/cRzHAUBasi5amZ9rIU4DYWJj
EQBhYmNkZWZnaGFzZGFzZGFzZC0AcXdldHJoeW9reG9jbTM0Nzl0aGNtczlxMjVoZHI5a2VyOHRo
Y2Zpc2RyaG9j0xlobA==
'/*!*/;
### INSERT INTO `abcd`.`test`
### SET
###? ?@1=1 /* INT meta=0 nullable=0 is_null=0 */
###? ?@2=2.2222222220000000803 /* DOUBLE meta=8 nullable=0 is_null=0 */
###? ?@3=1521626714 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
###? ?@4='2018-03-21 18:05:14' /* DATETIME(0) meta=0 nullable=1 is_null=0 */
###? ?@5='abc' /* STRING(40) meta=65064 nullable=1 is_null=0 */
###? ?@6='abcdefghasdasdasd' /* VARSTRING(16000) meta=16000 nullable=1 is_null=0 */
###? ?@7='qwetrhyokxocm3479thcms9q25hdr9ker8thcfisdrhoc' /* BLOB/TEXT meta=2 nullable=1 is_null=0 */
在這里將插入和刪除event放在一起說明,主要是兩者除了Header中event type不同外,其余的內容完全一致(WRITE_ROW_EVENTv2的event type為0x1e,DELETE_ROW_EVENT v2的event type為0x20)。也就是說,只要替換下事件類型,就可以從insert變為delete。
這類event MySQL 5.1.0 至5.1.15是v0版本,MySQL 5.1.15 至5.6.x為v1版本,MySQL 5.6.x之后為v2版本。
Post-Header的長度為0x0a。
e0 00 00 00 00 00 01 00 02 00
e0 00 00 00 00 00:table id 224。
01 00:flags,代表end of statement。
0x0001 end of statement
0x0002 no foreign key checks
0x0004 no unique key checks
0x0008 row has a columns
02 00:extra_data_len,需要大于等于2,官網上寫為extra row data的長度。
Body部分:
07:表有7個字段。
ff:官網上解釋為m_cols。
80:1000000,跟TABLE_MAP_EVENT上面一致,只看后七位,表示哪些字段有寫入null的情況。其中0代表寫入,1代表null。該字段的長度為INT((N + 7) / 8) bytes。N代表列數。
執行的語句是insert into test
values(1,2.222222222,now(),now(),'abc','abcdefghasdasdasd','qwetrhyokxocm3479thcms9q25hdr9ker8thcfisdrhoc');
01 00 00 00:首列是int,插入的值為1。
c2 79 bf 71 1c c7 01 40:第二列是double,上面已經看到sizeof(double)為8。
5a? b2 2e 5a :第三列值為1521626714,代表寫入的now()的時間戳。
99 9f 6b 21 4e:此處代表'2018-03-21 18:05:14',是datetime類型字段。
03 61 62 63:第五列,首先03代表位數,之后便是abc字符串。
11 00 61 62 63 64 65 66 67 68 61 73 64 61 73 64 61 73 64:第六列,首先0x11代表位數17位。之后出現了00,此處的00代表上一個字符串結束的標識,即將開始17位新的字符串。之后表示的便是abcdefghasdasdasd。
第七列的字符串較長,就不再贅述。
最后4位仍為校驗位。
?
九?UPDATE_ROW_EVENT
# at 1207
#180321 18:06:16 server id 1813309? end_log_pos 1369 CRC32 0x3cbdcd8d? Update_rows: table id 224 flags: STMT_END_F
BINLOG '
mC6yWhM9qxsAPQAAALcEAAAAAOAAAAAAAAEABGFiY2QABHRlc3QABwMFERL+D/wICAAA/iiAPgJ4
5WTVNA==
mC6yWh89qxsAogAAAFkFAAAAAOAAAAAAAAEAAgAH//+AAQAAAMJ5v3EcxwFAWrIuWpmfayFOA2Fi
YxEAYWJjZGVmZ2hhc2Rhc2Rhc2QtAHF3ZXRyaHlva3hvY20zNDc5dGhjbXM5cTI1aGRyOWtlcjh0
aGNmaXNkcmhvY4AKAAAAmDRG66iqCkBasi6YmZ9rIZAFYWJjZGUBAGEBAHONzb08
'/*!*/;
### UPDATE `abcd`.`test`
### WHERE
###? ?@1=1 /* INT meta=0 nullable=0 is_null=0 */
###? ?@2=2.2222222220000000803 /* DOUBLE meta=8 nullable=0 is_null=0 */
###? ?@3=1521626714 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
###? ?@4='2018-03-21 18:05:14' /* DATETIME(0) meta=0 nullable=1 is_null=0 */
###? ?@5='abc' /* STRING(40) meta=65064 nullable=1 is_null=0 */
###? ?@6='abcdefghasdasdasd' /* VARSTRING(16000) meta=16000 nullable=1 is_null=0 */
###? ?@7='qwetrhyokxocm3479thcms9q25hdr9ker8thcfisdrhoc' /* BLOB/TEXT meta=2 nullable=1 is_null=0 */
### SET
###? ?@1=10 /* INT meta=0 nullable=0 is_null=0 */
###? ?@2=3.3333300000000001262 /* DOUBLE meta=8 nullable=0 is_null=0 */
###? ?@3=1521626776 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
###? ?@4='2018-03-21 18:06:16' /* DATETIME(0) meta=0 nullable=1 is_null=0 */
###? ?@5='abcde' /* STRING(40) meta=65064 nullable=1 is_null=0 */
###? ?@6='a' /* VARSTRING(16000) meta=16000 nullable=1 is_null=0 */
###? ?@7='s' /* BLOB/TEXT meta=2 nullable=1 is_null=0 */
執行的sql為update test set a1=10,a2=3.33333,a3=now(),a4=now(),a5='abcde',a6='a',a7='s' where a1=1
在解析的binlog文件中可以看出,binlog記載的是一條記錄的完整的變化情況,即從前量變為后量的過程,并沒有記錄執行語句的條件等信息。
Fixed data部分與上面所述完全一致
Variable data部分:
第二位ff后又接了一位ff,與上面一致,為前量后量的m_cols。
之后的解析便與WRITE_ROW_EVENT中完全一致,唯一區別是記錄了舊值和新值的兩部分內容,此處請自行解析。
?
十 XID_EVENT
# at 970
#180321 18:05:14 server id 1813309? end_log_pos 1001 CRC32 0xb73f8e76? Xid = 8096890
COMMIT/*!*/;
Xid event比較短,主要是事務提交的時候回在最后生成一個xid號,有這個便代表事務已經成功提交了。
只有Body且一共就八位。
7a 8c 7b 00 00 00 00 00,為8096890,代表xid號。
?
十一 ROTATE_EVENT
# at 1880
#180321 18:06:37 server id 1813309? end_log_pos 1927 CRC32 0xe42f7923? Rotate to mysql-bin.000007? pos: 4
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
Binlog結束時的事件,與FORMAT_DESCRIPTION_EVENT一樣僅有一個。
Post-Header的長度為8位:
04 00 00 00 00 00 00 00:代表第一個事件開始的位置,為4.
Body:
6d 79 73 71 6c 2d 62 69 6e 2e 30 30 30 30 30 37 代表mysql-bin.000007,為下個binlog的文件名。
至此全部事件解析結束。
?
在之后的文章中,我們會逐漸介紹binlog主從復制機制和相關的二次開發工作。
總結
以上是生活随笔為你收集整理的binlog二进制文件解析的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: 足够应付面试的Spring事务源码阅读梳
- 下一篇: 研发应该懂的binlog知识(下)