文章來源於本人的印象筆記,如出現格式問題可訪問該鏈接查看原文
原創聲明:作者:Arnold.zhao 博客園地址:https://www.cnblogs.com/zh94
目錄
背景
開發了一段時間的canal,中間也陸陸續續出現了一些問題,今天趁着新開發的canal引擎已經上線,簡單匯總下之前所遇到的一些問題,本篇則主要是說明一下與MySQL相關的一些問題;
關於canal的介紹可以點擊這里。
關於MySql binlog的概念,可以看下MySql官網(中文)的這篇介紹:MySQL服務器日志;
想要先簡單理解下binlog日志的,可以參考如下內容:
在MySql中常用的數據庫表結構變更DDL和DML都會產生對應的操作日志,通過這個操作日志一般可以用來進行MySql故障后的數據恢復,以及MySql的主從同步使用;那么這個日志就是我們常說的MySql的binlog日志,binlog日志是一個二進制日志文件,並非是純粹的文本文件。
開啟MySql binlog
配置 binlog-format 為 ROW 模式,my.cnf 中配置如下
[mysqld]
log-bin=mysql-bin # 開啟 binlog
binlog-format=ROW # 選擇 ROW 模式
關於my.cnf中的一些更加詳細的信息,可以參考本人之前的另外一篇文章隨筆:MySql CPU彪高到百分之1000的排查思路,文章中包含了 mysqlDB5.7.20的實例安裝包,以及MySql服務器配置my.cnf的一些參數說明;
binlog-format
這里重點說一下binlog-format 配置的含義:
MySql中binlog-format 用來設置所產生的binLog日志格式,分別支持如下三種格式類型:
- STATEMENT:基於SQL語句的復制(statement-based replication, SBR)
- ROW:基於行的復制(row-based replication, RBR)
- MIXED:混合模式復制(mixed-based replication, MBR)
在 MySQL 5.7.7 之前,默認的格式是 STATEMENT,在 MySQL 5.7.7 及更高版本中,默認值是 ROW。
Statement
每一條會修改數據的sql都會記錄在binlog中
優點:不需要記錄每一行的變化,減少了binlog日志量,節約了IO, 提高了性能。
缺點:由於記錄的只是執行語句,為了這些語句能在slave上正確運行,因此還必須記錄每條語句在執行的時候的一些相關信息,以保證所有語句能在slave得到和在master端執行的時候相同的結果。另外mysql的復制,像一些特定函數的功能,slave與master要保持一致會有很多相關問題。
Row
5.1.5版本的MySQL才開始支持 row level 的復制,它不記錄sql語句上下文相關信息,僅保存哪條記錄被修改。
優點: binlog中可以不記錄執行的sql語句的上下文相關的信息,僅需要記錄那一條記錄被修改成什么了。所以row的日志內容會非常清楚的記錄下每一行數據修改的細節。而且不會出現某些特定情況下的存儲過程,或function,以及trigger的調用和觸發無法被正確復制的問題.
缺點:所有的執行的語句當記錄到日志中的時候,都將以每行記錄的修改來記錄,這樣可能會產生大量的日志內容。
將二進制日志格式設置為ROW時,有些更改仍然使用基於語句的格式,包括所有DDL語句,例如CREATE TABLE, ALTER TABLE,或 DROP TABLE。
Mixed
從5.1.8版本開始,MySQL提供了Mixed格式,實際上就是Statement與Row的結合。
在Mixed模式下,一般的語句修改使用statment格式保存binlog,如一些函數,statement無法完成主從復制的操作,則采用row格式保存binlog,MySQL會根據執行的每一條具體的sql語句來區分對待記錄的日志形式,也就是在Statement和Row之間選擇一種。
關於二進制日志格式的官網介紹可以參考這里
5.7版本以后默認情況下binlog的格式設置為ROW,ROW模式記錄的是每行實際數據的變更,所以將會導致對應的日志文件較大的情況,但是現在有SSD和萬兆光纖網絡,所以這些磁盤IO和網絡IO也是問題不大的;
原創聲明:作者:Arnold.zhao 博客園地址:https://www.cnblogs.com/zh94
binlog_row_image
在MySql5.7 版本以后除了binlog-format參數用來調整binlog日志的格式外,還多了另外一個參數:binlog_row_image,這個參數一般情況下不太會被注意的到,但實際的作用也是異常強烈的;
上面提到了,設置binlog-format為ROW后,MySql會記錄每一行數據修改的細節日志,在此之上,binlog_row_image則是對ROW的配置進行了更下一步的細分;
binlog_row_image可設置的值如下:
- FULL:記錄數據變更的所有前鏡像和后鏡像
- MINIMAL:binlog日志的前鏡像只記錄唯一識別列(唯一索引列、主鍵列),后鏡像只記錄修改列。
- NOBLOB:binlog記錄所有的列,就像full格式一樣。但對於BLOB或TEXT格式的列,如果他不是唯一識別列(唯一索引列、主鍵列),或者沒有修改,那就不記錄。
此處的前鏡像是指:數據庫表中修改前的內容;后鏡像則指:數據庫表中修改后的內容;
詳細解釋:
binlog_row_image=FULL,binlog記錄所有數據的前后鏡像,是最安全的設置,但性能也是最低的,如果數據出現誤操作,可以能通過flashback或binlog2sql等快速閃回工具恢復數據,如果對短時間前后數據安全性要求比較高,推薦此設置。
binlog_row_image=MINIMAL,binlog日志的前鏡像只記錄唯一識別列(唯一索引列、主鍵列),后鏡像只記錄修改列,性能是最高的,占用的資源等也是最少的,如果數據出現誤操作,不能通過flashback或binlog2sql等快速閃回工具恢復數據。
binlog_row_image=NOBLOB,binlog記錄所有的列,就像full格式一樣。但對於BLOB或TEXT格式的列,如果他不是唯一識別列(唯一索引列、主鍵列),或者沒有修改,那就不記錄。此設置可以簡單理解為在沒有text和blob等大字段時,效果同FULL一樣;在有text和blob等大字段時,如果大字段不是唯一識別列(唯一索引列、主鍵列),或者沒有修改,那就不記錄。
也就是說,雖然binlog每次記錄的數據格式還是按照行來進行日志記錄,但是通過設置binlog_row_image參數可以調整當前所記錄的行日志是只記錄行的變更前的日志鏡像的主鍵列,還是記錄行變更前的所有列的信息記錄等。可能到此處,對於不知道binlog所記錄的內容具體是何物的同學還是覺得有一絲迷茫,畢竟上述的都是概念,所以如下開始查看一下MySql庫中的binlog日志。使其更加清晰上述的概念
原創聲明:作者:Arnold.zhao 博客園地址:https://www.cnblogs.com/zh94
測試參數變更對日志記錄內容的影響
MySql測試服務器my.cnf的binlog配置如下:
# 指定binlog的產生日志目錄
log_bin = /opt/mysqlDB/logs/binLog/mysql-bin
binlog_format = ROW
expire_logs_days = 7 #超過7天的binlog刪除
# 當前開啟的為FULL模式
binlog_row_image = FULL
log_error = /opt/mysqlDB/logs/errorLog/mysql-error.log #錯誤日志路徑
slow_query_log = 1
long_query_time = 10 #慢查詢時間 超過1秒則為慢查詢
slow_query_log_file = /opt/mysqlDB/logs/slowLog/mysql-slow.log
performance_schema = 0
explicit_defaults_for_timestamp
lower_case_table_names = 1 #不區分大小寫
skip-external-locking #MySQL選項以避免外部鎖定。該選項默認開啟
default-storage-engine = InnoDB #默認存儲引擎
binlog_row_image 配置為FULL進行測試
在開啟對應的binlog日志,以及設置完對應的binlog_row_image的日志后,新建一條測試數據;
insert into whitelist(id,phone,create_time) values(2,'新增測試數據','2020-11-17')
切換至linux服務器查看當前MySql已生成的binlog日志信息,可以看到如下內容:
使用show master status 查看當前主庫正在使用的binlog的文件信息
使用 mysqlbinlog命令查看對應的binlog日志內容
[root@dev bin]# ./mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS /opt/mysqlDB/logs/binLog/mysql-bin.000011 | tail -n 25
#201117 15:56:44 server id 1 end_log_pos 3620 CRC32 0x0d682928 Anonymous_GTID last_committed=3 sequence_number=4 rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 3620
#201117 15:56:44 server id 1 end_log_pos 3701 CRC32 0xd969bac8 Query thread_id=53 exec_time=0 error_code=0
SET TIMESTAMP=1605599804/*!*/;
BEGIN
/*!*/;
# at 3701
#201117 15:56:44 server id 1 end_log_pos 3767 CRC32 0xb8d6a89d Table_map: `gangtise_test`.`whitelist` mapped to number 112
# at 3767
#201117 15:56:44 server id 1 end_log_pos 3831 CRC32 0x10b7810a Write_rows: table id 112 flags: STMT_END_F
### INSERT INTO `gangtise_test`.`whitelist`
### SET
### @1=2 /* INT meta=0 nullable=0 is_null=0 */
### @2='新增測試數據' /* VARSTRING(192) meta=192 nullable=1 is_null=0 */
### @3='2020-11-17 00:00:00' /* DATETIME(0) meta=0 nullable=1 is_null=0 */
# at 3831
#201117 15:56:44 server id 1 end_log_pos 3862 CRC32 0xc47a86ca Xid = 446
COMMIT/*!*/;
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日志
update whitelist set phone='修改測試數據' where id=2
重新查看binlog日志內容
[root@dev bin]# ./mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS /opt/mysqlDB/logs/binLog/mysql-bin.000011 | tail -n 25
#201117 16:11:24 server id 1 end_log_pos 4008 CRC32 0xa5dd2930 Query thread_id=53 exec_time=0 error_code=0
SET TIMESTAMP=1605600684/*!*/;
BEGIN
/*!*/;
# at 4008
#201117 16:11:24 server id 1 end_log_pos 4074 CRC32 0xafd4f105 Table_map: `gangtise_test`.`whitelist` mapped to number 112
# at 4074
#201117 16:11:24 server id 1 end_log_pos 4168 CRC32 0x82219047 Update_rows: table id 112 flags: STMT_END_F
### UPDATE `gangtise_test`.`whitelist`
### WHERE
### @1=2 /* INT meta=0 nullable=0 is_null=0 */
### @2='新增測試數據' /* VARSTRING(192) meta=192 nullable=1 is_null=0 */
### @3='2020-11-17 00:00:00' /* DATETIME(0) meta=0 nullable=1 is_null=0 */
### SET
### @1=2 /* INT meta=0 nullable=0 is_null=0 */
### @2='修改測試數據' /* VARSTRING(192) meta=192 nullable=1 is_null=0 */
### @3='2020-11-17 00:00:00' /* DATETIME(0) meta=0 nullable=1 is_null=0 */
# at 4168
#201117 16:11:24 server id 1 end_log_pos 4199 CRC32 0x6c4d894f Xid = 474
COMMIT/*!*/;
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_row_image配置為MINIMAL
重新新增一條數據
insert into whitelist(id,phone,create_time) values(3,'新增測試數據2','2020-11-17')
查看binlog日志如下
[root@dev bin]# ./mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS /opt/mysqlDB/logs/binLog/mysql-bin.000012 | tail -n 25
#201117 16:40:13 server id 1 end_log_pos 524 CRC32 0x74417b92 Anonymous_GTID last_committed=1 sequence_number=2 rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 524
#201117 16:40:13 server id 1 end_log_pos 605 CRC32 0x8c934110 Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=1605602413/*!*/;
BEGIN
/*!*/;
# at 605
#201117 16:40:13 server id 1 end_log_pos 671 CRC32 0x343d3210 Table_map: `gangtise_test`.`whitelist` mapped to number 112
# at 671
#201117 16:40:13 server id 1 end_log_pos 736 CRC32 0x710c0aac Write_rows: table id 112 flags: STMT_END_F
### INSERT INTO `gangtise_test`.`whitelist`
### SET
### @1=3 /* INT meta=0 nullable=0 is_null=0 */
### @2='新增測試數據2' /* VARSTRING(192) meta=192 nullable=1 is_null=0 */
### @3='2020-11-17 00:00:00' /* DATETIME(0) meta=0 nullable=1 is_null=0 */
# at 736
#201117 16:40:13 server id 1 end_log_pos 767 CRC32 0x05dd65be Xid = 22
COMMIT/*!*/;
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*/;
修改數據
update whitelist set phone='修改測試數據2' where id=3
查看binlog日志
[root@dev bin]# ./mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS /opt/mysqlDB/logs/binLog/mysql-bin.000012 | tail -n 25
#201117 16:45:45 server id 1 end_log_pos 832 CRC32 0x226707b1 Anonymous_GTID last_committed=2 sequence_number=3 rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 832
#201117 16:45:45 server id 1 end_log_pos 913 CRC32 0x0d67fee3 Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=1605602745/*!*/;
BEGIN
/*!*/;
# at 913
#201117 16:45:45 server id 1 end_log_pos 979 CRC32 0xd2ed2ad9 Table_map: `gangtise_test`.`whitelist` mapped to number 112
# at 979
#201117 16:45:45 server id 1 end_log_pos 1041 CRC32 0xb633518f Update_rows: table id 112 flags: STMT_END_F
### UPDATE `gangtise_test`.`whitelist`
### WHERE
### @1=3 /* INT meta=0 nullable=0 is_null=0 */
### SET
### @2='修改測試數據2' /* VARSTRING(192) meta=192 nullable=1 is_null=0 */
# at 1041
#201117 16:45:45 server id 1 end_log_pos 1072 CRC32 0x88b19729 Xid = 29
COMMIT/*!*/;
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*/;
如上,就可以很清晰的知道MySql中binlog_row_image配置后所產生的結果和不同,在配置為MINIMAL的情況下進行update時,就只會記錄前鏡像的唯一識別列,而后鏡像則只會記錄修改列;而並不是像FULL的配置時會記錄完整的修改前和修改后的鏡像;
由於canal中間件是直接接入的MySql的主從協議,模擬自身為MySql從節點以此獲取對應的MySql實時binlog日志信息,然后再進行實時的日志解析和數據同步等操作。由於canal自身只是從MySql master處獲取對應的binlog信息后進行解析再同步的操作,所以,當MySql所產生的日志內容不符合canal的解析規則,那么此時canal將會無解。。導致一系列的數據同步問題產生;
關於canal會產生上述問題的現象,可以查看github上canal的該issue:點擊這里查看issue;
本篇的內容,也算是對該issue問題的一個詳細說明而存在;
原創聲明:作者:Arnold.zhao 博客園地址:https://www.cnblogs.com/zh94
常用的MySql binlog命令
-- 查看主庫當前正在使用的binlog文件是那個文件
show master status
-- 查看從庫正在使用的binlog文件
show slave status
-- 查看當前master機器所有的binlog文件
show master logs
show master logs where log_name like '%004288%';
-- 查看當前Mysql配置
show variables
-- 查看當前MySql binLog的format值
show variables like 'binlog_format';
-- 查看當前MySql是否開啟bin log
show variables like 'log_bin';
-- 查看log相關的配置
show variables like '%log_%';
show variables like 'log_slave_updates';
# 事件查詢命令
# IN 'log_name' :指定要查詢的binlog文件名(不指定就是第一個binlog文件)
# FROM pos :指定從哪個pos起始點開始查起(不指定就是從整個文件首個pos點開始算)
# LIMIT [offset,] :偏移量(不指定就是0)
# row_count :查詢總條數(不指定就是所有行)
show binlog events [IN 'log_name'] [FROM pos] [LIMIT [offset,] row_count];
# 查看 binlog 內容
show binlog events;
# 查看具體一個binlog文件的內容 (in 后面為binlog的文件名)
show binlog events in 'master.000003';
# 設置binlog文件保存事件,過期刪除,單位天
set global expire_log_days=3;
# 刪除當前的binlog文件
reset master;
# 刪除slave的中繼日志
reset slave;
# 刪除指定日期前的日志索引中binlog日志文件
purge master logs before '2019-03-09 14:00:00';
# 刪除指定日志文件
purge master logs to 'master.000003';
# mysqlbinlog 的執行格式
mysqlbinlog [options] log_file ...
# 查看bin-log二進制文件(shell方式)
mysqlbinlog -v --base64-output=decode-rows /var/lib/mysql/master.000003
# 查看bin-log二進制文件(帶查詢條件)
mysqlbinlog -v --base64-output=decode-rows /var/lib/mysql/master.000003 \
--start-datetime="2019-03-01 00:00:00" \
--stop-datetime="2019-03-10 00:00:00" \
--start-position="5000" \
--stop-position="20000"
查看binglog開頭的MySql配置
show variables like '%binlog_%';
查看指定MySql的binglog日志
[root@dev bin]# ./mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS /opt/mysqlDB/logs/binLog/mysql-bin.000009 | tail -n 100
設置指定參數的配置
set binlog_row_image ='FULL';
設置指定的參數永久有效的方式是直接修改my.cnf配置,然后重啟即可;上述直接通過運行sql的方式修改配置,只能在當前的connection會話中有效,會話重新斷開后則配置無效,所以進行測試驗證的時候,直接修改my.cnf的方式是最有效的方式,
對於自建 MySQL , 需要先開啟 Binlog 寫入功能,配置 binlog-format 為 ROW 模式,my.cnf 中配置如下
[mysqld]
log-bin=mysql-bin # 開啟 binlog
binlog-format=ROW # 選擇 ROW 模式
server_id=1 # 配置 MySQL replaction 需要定義,不要和 canal 的 slaveId 重復
-- 創建canal賬號,並賦予mysql slave權限
CREATE USER canal IDENTIFIED BY 'canal';
GRANT SELECT, REPLICATION SLAVE, REPLICATION CLIENT ON *.* TO 'canal'@'%';
-- GRANT ALL PRIVILEGES ON *.* TO 'canal'@'%' ;
FLUSH PRIVILEGES;
-- 查詢賬戶權限
show grants for 'canal'
參考鏈接:
官方:MySql二進制文件說明;
官方:接入MySql Slave需遵從的協議規范
MySql CPU彪高到百分之1000的排查思路;
Canal 數據更新異常的issues地址
Mysql的Binlog原理;MySql Binlog介紹
binlog_row_image參數;MySQL 5.7貼心參數之binlog_row_image