目錄
背景
開發了一段時間的canal,中間也陸陸續續出現了一些問題,今天趁着新開發的canal引擎已經上線,簡單彙總下之前所遇到的一些問題,本篇則主要是說明一下與MySQL相關的一些問題;
關于canal的介紹可以點選
這裡。
關于MySql binlog的概念,可以看下MySql官網(中文)的這篇介紹:
MySQL伺服器日志;
想要先簡單了解下binlog日志的,可以參考如下内容:
在MySql中常用的資料庫表結構變更DDL和DML都會産生對應的記錄檔,通過這個記錄檔一般可以用來進行MySql故障後的資料恢複,以及MySql的主從同步使用;那麼這個日志就是我們常說的MySql的binlog日志,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也是問題不大的;
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日志。使其更加清晰上述的概念
測試參數變更對日志記錄内容的影響
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問題的一個詳細說明而存在;
-- 檢視主庫目前正在使用的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需遵從的協定規範 Canal 資料更新異常的issues位址 Mysql的Binlog原理 MySql Binlog介紹 binlog_row_image參數 MySQL 5.7貼心參數之binlog_row_image