1. 程式人生 > >MySQL Binlog解析(1)

MySQL Binlog解析(1)

cif 2.4 pear .... is_null 線程 uniq 會話 Circul

一、Binlog File

Binlog files start with a Binlog File Header followed by a series of Binlog Event

Binlog文件從一個Binlog文件頭開始,接著是一系列的Binlog事件。

技術分享圖片

1 Binlog File Header(文件頭)

A binlog file starts with a Binlog File Header [ fe ‘bin‘ ]

每一個binlog文件頭都是fe bin,十六進制如下(fe 62 69 6e):
$ hexdump -C /tmp/binlog-test.log
  00000000  fe 62 69 6e 19 6f c9 4c  0f 01 00 00 00 66 00 00  |.bin.o.L.....f..|
  00000010  00 6a 00 00 00 00 00 04  00 6d 79 73 71 6c 2d 70  |.j.......mysql-p|
  00000020  72 6f 78 79 2d 30 2e 37  2e 30 00 00 00 00 00 00  |roxy-0.7.0......|

2 Binlog Event(binlog事件)

The events contain the actual data that should be shipped from the master to the slave. Depending on the use, different events are sent.

事件包含主服務器發送到slave實際數據。根據實際使用情況,從而發送不同的事件。

The first event is either a START_EVENT_V3 or a FORMAT_DESCRIPTION_EVENT while the last event is either a STOP_EVENT or a ROTATE_EVENT.

第一個事件要麽是START_EVENT_V3,要麽是FORMAT_DESCRIPTION_EVENT,而最後一個事件要麽是STOP_EVENT,要麽是ROTATE_EVENT。在MySQL5.0以上版本中(binlog版本4),第一個事件都是FORMAT_DESCRIPTION_EVENT,最後一個是ROTATE_EVENT

A binlog event starts with a Binlog Event header and is followed by a Binlog Event Type specific data part

每個binlog事件都以一個binlog事件頭開始,然後是一個binlog事件類型特定的數據部分。

技術分享圖片

2.1 FORMAT_DESCRIPTION_EVENT

A format description event is the first event of a binlog for binlog-version 4. It describes how the other events are layed out.added in MySQL 5.0.0 as replacement for START_EVENT_V3

格式描述事件是binlog(版本4)的第一個事件。它描述了其他事件是如何發生的。在MySQL5.0版本中添加用來替代START_EVENT_V3事件

技術分享圖片

1) Event header(事件頭)

The binlog event header starts each event and is either 13 or 19 bytes long, depending on the binlog version.

事件頭根據binlog版本不同,分為13字節和19字節。mysql5+版本都是binlog v4版本,都是19個字節。

Binlog header field(字段組成):

timestamp (4) -- seconds since unix epoch:第一個字段是時間戳,占4個字節
event_type(1) -- see Binlog Event Type   :第二個字段是事件類型,占1個字節
server_id (4) -- server-id of the originating mysql-server. Used to filter out events in circular replication  :第三個字段是源mysql主機的serverid,占4個字節,用於過濾循環復制中的事件。
event_size (4) -- size of the event (header, post-header, body):第四個字段是事件大小,占4個字節,包括事件頭、事件體的總大小
log_pos (4) -- position of the next event:第五個字段是位置,占4個字節,表示下一個事件的位置
flags (2) -- see Binlog Event Flag:最後一個字段標誌狀態,占2個字節

2) Event body(事件體)

Binlog body field(字段組成):

binlog-version (2) -- version of this binlog format.         #binlog文件版本號,2個字節
mysql-server version (string.fix_len) -- [len=50] version of the MySQL Server that created the binlog. The string is evaluted to apply work-arounds in the slave.   #創建binlog的MySQL服務器版本,50個字節
create_timestamp (4) -- seconds since Unix epoch when the binlog was created  #binlog創建時的時間戳,4個字節
event_header_length (1) -- length of the Binlog Event Header of next events. Should always be 19。
event type header length (string.EOF) -- a array indexed by Binlog Event Type - 1 to extract the length of the event specific header.  這些字節由已經定義的event的個數決定,5.6,5.7為39個,也就是39個字節說明了他們fixed data(posted header)的長度
CRC32(4): CRC32校驗位,4個字節,文檔上沒有該字段,我通過分析binlog文件加上的。

3)【實戰解析】:

分析FORMAT_DESCRIPTION_EVENT在binlog文件中的實際存儲:

[root@shvm-5-39 mysql.bin]# /usr/local/mysql/bin/mysqlbinlog -vvv --base64-output=‘decode-rows‘ shvm-5-39.000001
# at 4
#171103 10:28:01 server id 2490050396  end_log_pos 123 CRC32 0x6c7b82a6         Start: binlog v 4, server v 5.7.19-log created 171103 10:28:01 at startup
ROLLBACK/*!*/;
# at 123
#171103 10:28:01 server id 2490050396  end_log_pos 154 CRC32 0x15e3db98         Previous-GTIDs
# [empty]
# at 154
#171103 10:28:04 server id 2490050396  end_log_pos 177 CRC32 0xbfbf2ea2         Stop
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*/;
--------------------------------------------------------------------------------------------------------
下面是十六進制格式:
[root@shvm-5-39 mysql.bin]# hexdump -C shvm-5-39.000001
00000000  fe 62 69 6e 31 d4 fb 59  0f 5c 27 6b 94 77 00 00  |.bin1..Y.\‘k.w..|
00000010  00 7b 00 00 00 00 00 04  00 35 2e 37 2e 31 39 2d  |.{.......5.7.19-|
00000020  6c 6f 67 00 00 00 00 00  00 00 00 00 00 00 00 00  |log.............|
00000030  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00000040  00 00 00 00 00 00 00 00  00 00 00 31 d4 fb 59 13  |...........1..Y.|
00000050  38 0d 00 08 00 12 00 04  04 04 04 12 00 00 5f 00  |8............._.|
00000060  04 1a 08 00 00 00 08 08  08 02 00 00 00 0a 0a 0a  |................|
00000070  2a 2a 00 12 34 00 01 a6  82 7b 6c 31 d4 fb 59 23  |**..4....{l1..Y#|
00000080  5c 27 6b 94 1f 00 00 00  9a 00 00 00 80 00 00 00  |\‘k.............|
00000090  00 00 00 00 00 00 98 db  e3 15 34 d4 fb 59 03 5c  |..........4..Y.\|
000000a0  27 6b 94 17 00 00 00 b1  00 00 00 00 00 a2 2e bf  |‘k..............|
000000b0  bf                                                |.|
000000b1
-------------------------------------------------------------------------------------------------------
分析如下:

第一部分:binlog文件頭,不同於事件頭。上面解釋過,前4個字節 fe 62 69 6e這個魔數表示文件頭,固定的。
第二部分:接下來就是binlog事件了,事件分事件頭和事件體,下面分析FORMAT_DESCRIPTION_EVENT如何存儲的?
1) 31 d4 fb 59:前4個字節代表字段timestamp,采用小端字節序,值是0x59fbd431 換算成十進制:5X16^7+9X16^6+f*16^5+b*16^4+d*16^3+4X16^2+3*16^1+1X16^0=1509676081 換成時間:2017-11-03 10:28:01
2) 0f:第5個字節代表event_type=15,代表是FORMAT_DESCRIPTION_EVENT
3) 5c 27 6b 94:再4個字節代表server_id=0x946b275c 換算成十進制:9x16^7+4x16^6+6x16^5+b*16^4+2x16^3+7x16^2+5x16+c=2490050396
4) 77 00 00 00:這4個字節代表event_size=0x00000077 換成十進制:7*16^1+7*16^0=119
5) 7b 00 00 00:4個字節代表log_pos=0x0000007b 換成十進制:123,表示下一個event起始偏移,對應binlog文件中end_log_pos=123
6) 00 00:2個字節表示flags=0,表示該binlog文件已經被關閉,如果打開時為1,最後一個正在寫入的binlog文件flags=1
7) 04 00:2個字節表示binlog版本號=4
8) 35 2e 37 2e 31 39 2d 6c 6f 67 00 00 00 00 00  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  00 00 00:這50字節MySQL服務器版本server v 5.7.19-log
9) 31 d4 fb 59:0x59fbd431表示binlog創建時間戳,1509676081 換成時間:2017-11-03 10:28:01
10)13:這一個字節表示event_header_length=0x13=19,事件頭是19字節
11)38 0d 00 08 00 12 00 04  04 04 04 12 00 00 5f 00 04 1a 08 00 00 00 08 08  08 02 00 00 00 0a 0a 0a 2a 2a 00 12 34 00 01:這39個字節表示有39個event
12)a6 82 7b 6c:0x6c7b82a6表示CRC32的值,同binlog文件中的值

以上分析的內容同binlog文件裏看到的一致。

2.2 ROTATE_EVENT

1)觸發條件

When a binary log file exceeds a size limit, a ROTATE_EVENT is written at the end of the file that points to the next file in the squence. This event is information for the slave to know the name of the next binary log it is going to receive.

# 當一個二進制日誌文件超過大小限制時(max_binlog_size),ROTATE_EVENT將被觸發,在文件的末尾寫入,指向下一個文件。這個事件是給slave的信息,以便知道它將要接收的下一個二進制日誌的名稱。
# 當執行flush logs觸發ROTATE_EVENT並生成新二進制文件,宕機不能觸發該事件

2)存儲格式

技術分享圖片

Fixed data part:

8 bytes. The position of the first event in the next log file. Always contains the number 4 (meaning the next event starts at position 4 in the next binary log). This field is not present in v1; presumably the value is assumed to be 4.

Variable data part:

The name of the next binary log. The filename is not null-terminated. Its length is the event size minus the size of the fixed parts.

1、事件頭部分上面已經說過,占用19個字節,所有事件都是一樣的。
2、事件體部分:
      固定數據部分:8個字節,記錄下一個二進制文件第一個事件的位置,該值總是等於4,也就是在新的binlog文件at 4.
      可變數據部分:記錄下一個binlog文件名,該值不能為空字符。長度等於 event size減去固定數據部分。

2.3 STOP_EVENT

1)觸發條件

A master writes the event to the binary log when it shuts down
A slave writes the event to the relay log when it shuts down or when a RESET SLAVE statement is executed

master開啟binlog,當數據庫shut down時
slave開啟binlog,當數據庫shut down或者執行reset slave語句時

2)存儲格式

技術分享圖片

1、事件頭,占用19個字節。
2、事件體部分:
      固定數據部分:Empty
      可變數據部分:Empty
      CRC校驗:占用4個字節
一共占用23個字節

2.4 QUERY_EVENT

The query event is used to send text querys right the binlog.

查詢事件用於向binlog發送文本查詢。

1)觸發條件

QUERY_EVENT類型的事件通常在以下幾種情況下使用:
    # 事務開始時,執行的BEGIN操作
    # STATEMENT格式中的DML操作
    # ROW格式中的DDL操作

2)存儲格式

技術分享圖片

1、事件頭,占用19個字節。
2、事件體部分:
      固定數據部分:
        # 4 bytes. The ID of the thread that issued this statement. Needed for temporary tables. This is also useful for a DBA for knowing who did what on the master.//4個字節存儲thread id
        # 4 bytes. The time in seconds that the statement took to execute. Only useful for inspection by the DBA.//4個字節 存儲執行時間,單位秒
        # 1 byte. The length of the name of the database which was the default database when the statement was executed. This name appears later, in the variable data part. It is necessary for statements such as INSERT INTO t VALUES(1) that don‘t specify the database and rely on the default database previously selected by USE.//1個字節,存儲執行sql默認數據庫名的長度
        # 2 bytes. The error code resulting from execution of the statement on the master. //2個字節存儲錯誤編碼值,0代表沒有錯誤。如果非零一般出現在非事務性表操作,如insert...select在插入1000條到mysiam失敗了,部分數據寫入到了binlog文件。
        # 2 bytes (not present in v1, v3). The length of the status variable block.//2個字節存儲狀態變量塊的長度

      可變數據部分:
        # Zero or more status variables (not present in v1, v3). Each status variable consists of one byte code identifying the variable stored, followed by the value of the variable. The format of the value is variable-specific, as described later.
          存儲上下文一些set 變量,key-value形式存儲,它的長度在固定數據最後一個字段已經知道
        # The default database name (null-terminated).
          默認的數據庫名,在固定數據部分已經知道它的長度
        # 00:默認的1個字節
        # The SQL statement. The slave knows the size of the other fields in the variable part (the sizes are given in the fixed data part), so by subtraction it can know the size of the statement.
          存儲SQL語句,它的長度可以通過event-size 減去 公有事件頭19 減去 固定數據部分長度 減去 可變數據的變量長度 減去可變數據的數據庫名長度 減去 CRC32(4個字節) 減去 1個字節(默認00)

3)實戰分析

結合hexdump出來的數據和mysqlbinlog解析出的日誌進行分析:

技術分享圖片

# at 259
#180530 18:42:31 server id 2490050396  end_log_pos 370 CRC32 0x6a9644c6         Query   thread_id=7322991       exec_time=0     error_code=0
use `darren`/*!*/;
SET TIMESTAMP=1527676951/*!*/;
SET @@session.pseudo_thread_id=7322991/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=0/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
alter table t add index idx_1(id)
/*!*/;
-------公有事件頭--------
19個字節這裏再分析

--------固定數據部分(私有事件頭)-----

1、thread_id:4個字節,6f bd 6f 00,十進制即7322991.存儲了不同連接或會話的線程ID
2、execution time:4個字節,00 00 00 00,查詢從開始執行到記錄到binlog所花時間,單位s
3、schema length:1個字節,06,schema字符長度6。即darren
4、error code:2個字節,00 00,錯誤碼
5、status-var length:2個字節,23 00,status-var的長度,為35

---------可變數據部分(事件體)--------
6、status var:35個字節,即00 00 00 00 00 01 00 00 00 00 00 00 00 00 06 03 73 74 64 04 21  00 21 00 21 00 0c 01 64 61 72 72 65 6e 00。以KV對的形式保存起來的一些了由SET命令設置的上下文信息。如SET @@session.sql_mode=0 等
7、schema:6字節,即64 61 72 72 65 6e,查詢對應的asci碼,剛好對應darren。表示選擇的數據庫是darren
8、00:默認1個字節
9、sql文本:33個字節,即:61 6c 74 65 72 20 74 61 62 6c 65  20 74 20 61 64 64 20 69 6e 64 65 78 20 69 64 78  5f 31 28 69 64 29,query的文本格式,裏面存儲的是BEGIN或原生的SQL等

MySQL Binlog解析(1)