binlog想必大家都不陌生，在主從復制或者某些情況下的數據恢復會用到。由于binlog是二進制數據，要查看一般都借助mysqlbinlog工具。這篇筆記分析了binlog格式，希望能夠了解下mysqlbinlog工具背后所做的事情。
1.什么時候寫binlog
在說明什么時候寫binlog前，先簡單介紹下binlog的用途。binlog是二進制日志文件，用于記錄mysql的數據更新或者潛在更新(比如delete語句執行刪除而實際并沒有符合條件的數據)，在mysql主從復制中就是依靠的binlog。在mysql中開啟binlog需要設置my.cnf中的log_bin參數，另外也可以通過binlog_do_db
指定要記錄binlog的數據庫和binlog_ignore_db指定不記錄binlog的數據庫。對運行中的mysql要啟用binlog可以通過命令set sql_log_bin=1來設置。設置完成，我們就可以來測試binlog了。
需要注意下innodb引擎中的redo/undo log與mysql binlog是完全不同的日志，它們主要有以下幾個區別：
-
a）層次不同。redo/undo log是innodb層維護的，而binlog是mysql server層維護的，跟采用何種引擎沒有關系，記錄的是所有引擎的更新操作的日志記錄。innodb的redo/undo log更詳細的說明可以參見姜承堯的《mysql技術內幕-innodb存儲引擎》一書中相關章節。
-
b）記錄內容不同。redo/undo日志記錄的是每個頁的修改情況，屬于物理日志+邏輯日志結合的方式（redo log物理到頁，頁內采用邏輯日志，undo log采用的是邏輯日志），目的是保證數據的一致性。binlog記錄的都是事務操作內容，比如一條語句DELETE FROM TABLE WHERE i > 1之類的，不管采用的是什么引擎，當然格式是二進制的，要解析日志內容可以用這個命令mysqlbinlog -vv BINLOG。
-
c）記錄時機不同。redo/undo日志在事務執行過程中會不斷的寫入;而binlog僅僅在事務提交后才寫入到日志，之前描述有誤，binlog是在事務最終commit前寫入的，多謝anti-semicolon 指出。當然，binlog什么時候刷新到磁盤跟參數sync_binlog相關。
顯然，我們執行SELECT等不涉及數據更新的語句是不會記binlog的，而涉及到數據更新則會記錄。要注意的是，對支持事務的引擎如innodb而言，必須要提交了事務才會記錄binlog。
binlog刷新到磁盤的時機跟sync_binlog參數相關，如果設置為0，則表示MySQL不控制binlog的刷新，由文件系統去控制它緩存的刷新，而如果設置為不為0的值則表示每sync_binlog次事務，MySQL調用文件系統的刷新操作刷新binlog到磁盤中。設為1是最安全的，在系統故障時最多丟失一個事務的更新，但是會對性能有所影響，一般情況下會設置為100或者0，犧牲一定的一致性來獲取更好的性能。
通過命令SHOW MASTER LOGS可以看到當前的binlog數目。如下面就是我機器上的mysql的binlog情況，第一列是binlog文件名，第二列是binlog文件大小。可以通過設置expire_logs_days來指定binlog保留時間，要手動清理binlog可以通過指定binlog名字或者指定保留的日期，命令分別是:purge master logs to BINLOGNAME;和purge master logs before DATE;。
...... |?mysql-bin.000018?|???????515?| |?mysql-bin.000019?|???????504?| |?mysql-bin.000020?|???????107?| +------------------+-----------+
2 binlog格式解析
2.1 binlog文件格式簡介
binlog格式分為statement，row以及mixed三種，mysql5.5默認的還是statement模式，當然我們在主從同步中一般是不建議用statement模式的，因為會有些語句不支持，比如語句中包含UUID函數，以及LOAD DATA IN FILE語句等，一般推薦的是mixed格式。暫且不管這三種格式的區別，看看binlog的存儲格式是什么樣的。binlog是一個二進制文件集合，當然除了我們看到的mysql-bin.xxxxxx這些binlog文件外，還有個binlog索引文件mysql-bin.index。如官方文檔中所寫，binlog格式如下：
-
binlog文件以一個值為0Xfe62696e的魔數開頭，這個魔數對應0xfe ‘b”i”n’。
-
binlog由一系列的binlog event構成。每個binlog event包含header和data兩部分。
-
header部分提供的是event的公共的類型信息，包括event的創建時間，服務器等等。
-
data部分提供的是針對該event的具體信息，如具體數據的修改。
-
從mysql5.0版本開始，binlog采用的是v4版本，第一個event都是format_desc event 用于描述binlog文件的格式版本，這個格式就是event寫入binlog文件的格式。關于之前版本的binlog格式，可以參見http://dev.mysql.com/doc/internals/en/binary-log-versions.html
-
接下來的event就是按照上面的格式版本寫入的event。
-
最后一個rotate event用于說明下一個binlog文件。
-
binlog索引文件是一個文本文件，其中內容為當前的binlog文件列表。比如下面就是一個mysql-bin.index文件的內容。
/var/log/mysql/mysql-bin.000019 /var/log/mysql/mysql-bin.000020 /var/log/mysql/mysql-bin.000021
接下來分析下幾種常見的event，其他的event類型可以參見官方文檔。event數據結構如下：
+=====================================+ |?event??|?timestamp?????????0?:?4????| |?header?+----------------------------+ |????????|?type_code?????????4?:?1????| |????????+----------------------------+ |????????|?server_id?????????5?:?4????| |????????+----------------------------+ |????????|?event_length??????9?:?4????| |????????+----------------------------+ |????????|?next_position????13?:?4????| |????????+----------------------------+ |????????|?flags????????????17?:?2????| |????????+----------------------------+ |????????|?extra_headers????19?:?x-19?| +=====================================+ |?event??|?fixed?part????????x?:?y????| |?data???+----------------------------+ |????????|?variable?part??????????????| +=====================================+
2.2 format_desc event
下面是我在FLUSH LOGS之后新建的一個全新的binlog文件mysql-bin.000053，從binlog第一個event也就是format_desc event開始分析（mysql日志是小端字節序）：
root@ubuntu:/var/log/mysql#?hexdump?-C?mysql-bin.000053 00000000??fe?62?69?6e?b8?b2?7f?56??0f?04?00?00?00?67?00?00??|.bin...V.....g..| 00000010??00?6b?00?00?00?01?00?04??00?35?2e?35?2e?34?36?2d??|.k.......5.5.46-| 00000020??30?75?62?75?6e?74?75?30??2e?31?34?2e?30?34?2e?32??|0ubuntu0.14.04.2| 00000030??2d?6c?6f?67?00?00?00?00??00?00?00?00?00?00?00?00??|-log............| 00000040??00?00?00?00?00?00?00?00??00?00?00?00?00?00?00?13??|................| 00000050??38?0d?00?08?00?12?00?04??04?04?04?12?00?00?54?00??|8.............T.| 00000060??04?1a?08?00?00?00?08?08??08?02?00?????????????????|...........|
對照官方文檔中的說明來看下format_desc event格式：
+=====================================+ |?event??|?timestamp?????????0?:?4????| |?header?+----------------------------+ |????????|?type_code?????????4?:?1????|?=?FORMAT_DESCRIPTION_EVENT?=?15 |????????+----------------------------+ |????????|?server_id?????????5?:?4????| |????????+----------------------------+ |????????|?event_length??????9?:?4????|?>=?91 |????????+----------------------------+ |????????|?next_position????13?:?4????| |????????+----------------------------+ |????????|?flags????????????17?:?2????| +=====================================+ |?event??|?binlog_version???19?:?2????|?=?4 |?data???+----------------------------+ |????????|?server_version???21?:?50???| |????????+----------------------------+ |????????|?create_timestamp?71?:?4????| |????????+----------------------------+ |????????|?header_length????75?:?1????| |????????+----------------------------+ |????????|?post-header??????76?:?n????|?=?array?of?n?bytes,?one?byte?per?event |????????|?lengths?for?all????????????|???type?that?the?server?knows?about |????????|?event?types????????????????| +=====================================+
前面4個字節是固定的magic number,值為0x6e6962fe。接著是一個format_desc event，先看下19個字節的header。這19個字節中前4個字節0x567fb2b8是時間戳，第5個字節0x0f是event type，接著4個字節0x00000004是server_id，再接著4個字節0x00000067是長度103，然后的4個字節0x0000006b是下一個event的起始位置107，接著的2個字節的0x0001是flag（1為LOG_EVENT_BINLOG_IN_USE_F，標識binlog還沒有關閉，binlog關閉后，flag會被設置為0），這樣4+1+4+4+4+2=19個字節的公共頭就完了(extra_headers暫時沒有用到)。然后是這個event的data部分，event的data分為Fixed data和Variable data兩部分，其中Fixed data是event的固定長度和格式的數據，Variable data則是長度變化的數據，比如format_desc event的Fixed data長度是0x54=84個字節。下面看下這84=2+50+4+1+27個字節的分配：開始的2個字節0x0004為binlog的版本號4，接著的50個字節為mysql-server版本，如我的版本是5.5.46-0ubuntu0.14.04.2-log，與SELECT version();查看的結果一致。接下來4個字節是binlog創建時間，這里是0；然后的1個字節0x13是指之后所有event的公共頭長度，這里都是19；接著的27個字節中每個字節為mysql已知的event（共27個）的Fixed data的長度；可以發現format_desc event自身的Variable data部分為空。
2.3 rotate event
接著我們不做額外操作，直接FLUSH LOGS，可以看到一個rotate event，此時的binlog內容如下:
...... 00000060??.................................?c2?b3?7f?56?04??|..............V.| 00000070??04?00?00?00?2b?00?00?00??96?00?00?00?00?00?04?00??|....+...........| 00000080??00?00?00?00?00?00?6d?79??73?71?6c?2d?62?69?6e?2e??|......mysql-bin.| 00000090??30?30?30?30?35?34?????????????????????????????????|000054| 00000096
前面的內容跟之前的幾乎一致，除了format_desc event的flag從0x0001變成了0x0000。然后從0x567fb3c2開始是一個rotate event。依照前面的分析，前面19個字節為event的header，其event type是0x04，長度為0x2b=43，下一個event起始位置為0x96=150，然后是flag為0x0000，接著是event data部分，首先的8個字節為Fixed data部分，記錄的是下一個binlog的位置偏移4，而余下來的43-19-8=16個字節為Variable data部分，記錄的是下一個binlog的文件名mysql-bin.000054。對照mysqlbinlog -vv mysql-bin.000053可以驗證。
ssj@ubuntu:/var/log/mysql$?mysqlbinlog?-vv?mysql-bin.000053? ... #?at?4 #151227?17:43:20?server?id?4??end_log_pos?107?????Start:?binlog?v?4,?server?v?5.5.46-0ubuntu0.14.04.2-log?created?151227?17:43:20 BINLOG?' uLJ/Vg8EAAAAZwAAAGsAAAAAAAQANS41LjQ2LTB1YnVudHUwLjE0LjA0LjItbG9nAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA== '/*!*/; #?at?107 #151227?17:47:46?server?id?4??end_log_pos?150?????Rotate?to?mysql-bin.000054??pos:?4 ...
2.4 query event
刷新binlog，設置binlog_format=statement，創建一個表CREATE TABLEtt(ivarchar(100) DEFAULT NULL) ENGINE=InnoDB, 然后在測試表tt中插入一條數據insert into tt values(‘abc’)，會產生3個event，包括2個query event和1個xid event。其中2個query event分別是BEGIN以及INSERT 語句，而xid event則是事務提交語句（xid event是支持XA的存儲引擎才有的，因為測試表tt是innodb引擎的，所以會有。如果是myisam引擎的表，也會有BEGIN和COMMIT,只不過COMMIT會是一個query event而不是xid event）。
mysql>?show?binlog?events?in?'mysql-bin.000060'; +------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+ |?Log_name?????????|?Pos?|?Event_type??|?Server_id?|?End_log_pos?|?Info???????????????????????????????????????????????????| +------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+ |?mysql-bin.000060?|???4?|?Format_desc?|?????????4?|?????????107?|?Server?ver:?5.5.46-0ubuntu0.14.04.2-log,?Binlog?ver:?4?| |?mysql-bin.000060?|?107?|?Query???????|?????????4?|?????????175?|?BEGIN??????????????????????????????????????????????????| |?mysql-bin.000060?|?175?|?Query???????|?????????4?|?????????266?|?use?`test`;?insert?into?tt?values('abc')???????????????| |?mysql-bin.000060?|?266?|?Xid?????????|?????????4?|?????????293?|?COMMIT?/*?xid=138?*/???????????????????????????????????| +------------------+-----+-------------+-----------+-------------+--------------------------------------------------
binlog如下：
....... 0000006b??01?9d?82?56?02?04?00?00??00?44?00?00?00?af?00?00??|...V.....D......| 0000007b??00?08?00?26?00?00?00?00??00?00?00?04?00?00?1a?00??|...&............| 0000008b??00?00?00?00?00?01?00?00??00?00?00?00?00?00?06?03??|................| 0000009b??73?74?64?04?21?00?21?00??08?00?74?65?73?74?00?42??|std.!.!...test.B| 000000ab??45?47?49?4e???????????????????????????????????????|EGIN| 000000af??01?9d?82?56?02?04?00?00??00?5b?00?00?00?0a?01?00??|...V.....[......| 000000bf??00?00?00?26?00?00?00?00??00?00?00?04?00?00?1a?00??|...&............| 000000cf??00?00?00?00?00?01?00?00??00?00?00?00?00?00?06?03??|................| 000000df??73?74?64?04?21?00?21?00??08?00?74?65?73?74?00?69??|std.!.!...test.i| 000000ef??6e?73?65?72?74?20?69?6e??74?6f?20?74?74?20?76?61??|nsert?into?tt?va| 000000ff??6c?75?65?73?28?27?61?62??63?27?29?????????????????|lues('abc')| 0000010a??01?9d?82?56?10?04?00?00??00?1b?00?00?00?25?01?00??|...V.........%..| 0000011a??00?00?00?8a?00?00?00?00??00?00?00?????????????????|...........|
拋開format_desc event，從0000006b開始分析第一個query event。頭部跟之前的event一樣，只是query event的type為0x02，長度為0x44=64，下一個event位置為0xaf=175。flag為8，接著是data部分，從format_desc event我們可以知道query event的Fixed data部分為13個字節，因此也可以算出Variable data部分為64-19-13=32字節。
-
Fixed data：首先的4個字節0x00000026為執行該語句的thread id，接下來的4個字節是執行的時間0(以秒為單位)，接下來的1個字節0x04是語句執行時的默認數據庫名字的長度，我這里數據庫是test，所以長度為4.接著的2個字節0x0000是錯誤碼（注：通常情況下錯誤碼是0表示沒有錯誤，但是在一些非事務性表如myisam表執行INSERT…SELECT語句時可能插入部分數據后遇到duplicate-key錯誤會產生錯誤碼1062，或者是事務性表在INSERT…SELECT出錯不會插入部分數據，但是在執行過程中CTRL+C終止語句也可能記錄錯誤碼。slave db在復制時會執行后檢查錯誤碼是否一致，如果不一致，則復制過程會中止）,接著2個字節0x001a為狀態變量塊的長度26。
-
Variable data：從0x001a之后的26個字節為狀態變量塊（這個暫時先不管），然后是默認數據庫名test，以0x00結尾，然后是sql語句BEGIN，接下來就是第2個query event的內容了。
第二個query event與第一個格式一樣，只是執行語句變成了insert into tt values(‘abc’)。
第三個xid event為COMMIT語句。前19個字節是通用頭部，type是16。data部分中Fixed data為空，而variable data為8個字節，這8個字節0x000000008a是事務編號（注意事務編號不一定是小端字節序，因為是從內存中拷貝到磁盤的，所以這個字節序跟機器相關）。
2.5 table_map event & write_rows event
這兩個event是在binlog_format=row的時候使用，設置binlog_format=row，然后創建一個測試表
CREATE?TABLE?`trow`?( ??`i`?int(11)?NOT?NULL, ??`c`?varchar(10)?DEFAULT?NULL, ??PRIMARY?KEY?(`i`) )?ENGINE=InnoDB?DEFAULT?CHARSET=latin1`
執行語句INSERT INTO trow VALUES(1, NULL), (2, ‘a’)，這個語句會產生一個query event，一個table_map event、一個write_rows event以及一個xid event。
mysql>?show?binlog?events?in?'mysql-bin.000074'; |?Log_name?????????|?Pos?|?Event_type??|?Server_id?|?End_log_pos?|?Info???????????????????????????????????????????????????| +------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+ |?mysql-bin.000074?|???4?|?Format_desc?|?????????4?|?????????107?|?Server?ver:?5.5.46-0ubuntu0.14.04.2-log,?Binlog?ver:?4?| |?mysql-bin.000074?|?107?|?Query???????|?????????4?|?????????175?|?BEGIN??????????????????????????????????????????????????| |?mysql-bin.000074?|?175?|?Table_map???|?????????4?|?????????221?|?table_id:?50?(test.trow)???????????????????????????????| |?mysql-bin.000074?|?221?|?Write_rows??|?????????4?|?????????262?|?table_id:?50?flags:?STMT_END_F?????????????????????????| |?mysql-bin.000074?|?262?|?Xid?????????|?????????4?|?????????289?|?COMMIT?/*?xid=245?*/
對應的mysql-bin.000074數據如下：
... #query?event?(BEGIN) 0000006b??95?2a?85?56?02?04?00?00??00?44?00?00?00?af?00?00??|.*.V.....D......| 0000007b??00?08?00?26?00?00?00?00??00?00?00?04?00?00?1a?00??|...&............| 0000008b??00?00?00?00?00?01?00?00??00?00?00?00?00?00?06?03??|................| 0000009b??73?74?64?04?21?00?21?00??08?00?74?65?73?74?00?42??|std.!.!...test.B| 000000ab??45?47?49?4e???????????????????????????????????????|EGIN| #table_map?event 000000af??95?2a?85?56?13?04?00?00??00?2e?00?00?00?dd?00?00??|.*.V............| 000000bf??00?00?00?32?00?00?00?00??00?01?00?04?74?65?73?74??|...2........test| 000000cf??00?04?74?72?6f?77?00?02??03?0f?02?0a?00?02????????|..trow........| #write_rows?event 000000dd??95?2a?85?56?17?04?00?00??00?29?00?00?00?06?01?00??|.*.V.....)......| 000000ed??00?00?00?32?00?00?00?00??00?01?00?02?ff?fe?01?00??|...2............| 000000fd??00?00?fc?02?00?00?00?01??61???????????????????????|........a| #xid?event 00000106??95?2a?85?56?10?04?00?00??00?1b?00?00?00?21?01?00??|.*.V.........!..| 00000116??00?00?00?f5?00?00?00?00??00?00?00?????????????????|...........|
0x0000006b-0x000000ae為query event，語句是BEGIN,前面已經分析過。
table_map event
0x0000000af開始為table_map event。除去頭部19個字節，Fixed data為8個字節，前面6個字節0x32=50為table id，接著2個字節0x0001為flags。
Variable data部分，首先1個字節0x04為數據庫名test的長度，然后5個字節是數據庫名test+結束符。接著1個字節0x04為表名長度，接著5個字節為表名trow+結束符。接著1個字節0x02為列的數目。而后是2個列的類型定義，分別是0x03和0x0f（列的類型MYSQL_TYPE_LONG為0x03，MYSQL_TYPE_VARCHAR為0x0f)。接著是列的元數據定義，首先0x02表示元數據長度為2，因為MYSQL_TYPE_LONG沒有元數據，而MYSQL_TYPE_VARCHAR元數據長度為2。接著的0x000a就是MYSQL_TYPE_VARCHAR的元數據，表示我們在定義表時的varchar字段c長度為10，最后一個字節0x02為掩碼，表示第一個字段i不能為NULL。關于列的類型以及元數據等更詳細的信息可以參見http://dev.mysql.com/doc/internals/en/table-map-event.html。
write_rows event
從0x000000dd開始為write_rows event，除去頭部19個字節，前6個字節0x32也是table id，然后兩個字節0x0001為flags。接著的1個字節0x02為表中列的數目。然后1個字節0xff各個bit標識各列是否存在值，這里表示都存在。
接著的就是插入的各行數據了。第1個字節0xfe的各個bit標識該行變化之后各列是否為NULL，為NULL記為1.這里表示第1列不為NULL，因為第一行數據插入的是(1,NULL)。接下來是各列的數據，第一列是MYSQL_TYPE_LONG,長度為4個字節，所以0x00000001就是這個值。第二列是NULL不占字節。接下來是第二行，先是0xfc標識兩列都不為NULL，先讀取第一列的4個字節0x00000002也就是我們插入的數字2，然后讀取第二列，先是一個字節的長度0x01，然后是內容0x61也就是字符’a’。到此，write_rows event也就分析完了。rows相關的event還有update_rows event和delete_rows event等，欲了解更多可以參見官方文檔。
最后是xid event，之前已經分析過，不再贅述。
2.6 intvar event
intvar event在binlog_format=statement時使用到，用于自增鍵類型auto_increment，十分重要。intval event的Fixed data部分為空，而Variable data部分為9個字節，第1個字節用于標識自增事件類型 LAST_INSERT_ID_EVENT = 1 or INSERT_ID_EVENT = 2，余下的8個字節為自增ID。
創建一個測試表 create table tinc (i int auto_increment primary key, c varchar(10)) engine=innodb;，然后執行一個插入語句INSERT INTO tinc(c) values(‘abc’);就可以看到intvar event了，這里的自增事件類型為INSERT_ID_EVENT。而如果用語句INSERT INTO tinc(i, c) VALUES(LAST_INSERT_ID()+1, ‘abc’)，則可以看到自增事件類型為LAST_INSERT_ID_EVENT的intvar event。
|?Log_name?????????|?Pos?|?Event_type??|?Server_id?|?End_log_pos?|?Info???????????????????????????????????????????????????| +------------------+-----+-------------+-----------+------------- |?mysql-bin.000079?|???4?|?Format_desc?|?????????4?|?????????107?|?Server?ver:?5.5.46-0ubuntu0.14.04.2-log,?Binlog?ver:?4?| |?mysql-bin.000079?|?107?|?Query???????|?????????4?|?????????175?|?BEGIN??????????????????????????????????????????????????| |?mysql-bin.000079?|?175?|?Intvar??????|?????????4?|?????????203?|?INSERT_ID=1????????????????????????????????????????????| |?mysql-bin.000079?|?203?|?Query???????|?????????4?|?????????299?|?use?`test`;?insert?into?tinc(c)?values('abc')??????????| |?mysql-bin.000079?|?299?|?Xid?????????|?????????4?|?????????326?|?COMMIT?/*?xid=263?*/
3 簡單總結
上面提到，binlog有三種格式，各有優缺點：
-
statement：基于SQL語句的模式，某些語句和函數如UUID, LOAD DATA INFILE等在復制過程可能導致數據不一致甚至出錯。
-
row：基于行的模式，記錄的是行的變化，很安全。但是binlog會比其他兩種模式大很多，在一些大表中清除大量數據時在binlog中會生成很多條語句，可能導致從庫延遲變大。
-
mixed：混合模式，根據語句來選用是statement還是row模式。
不同版本的mysql在主從復制要慎重，雖然mysql5.0之后都用的V4版本的binlog了，估計還是會有些坑在里面，特別是高版本為主庫，低版本為從庫時容易出問題。在主從復制時最好還是主庫從庫版本一致，至少是大版本一致。mysql復制是個大的話題，希望有時間能單獨總結一篇筆記。
【相關推薦】
