一、報錯資訊
近期項目實施同僚對系統更新,對test.test_tab_t1的某個字段進行變更,SQL語句如下:
ALTER TABLE TEST.TEST_TAB_T1 MODIFY BXXX VARCHAR(200);
在該項目項目在做系統更新之後,出現MySQL主從同步報錯,報錯資訊如下:
mysql>show slave status\G
Master_Log_File: binlog.000233
Read_Master_Log_Pos: 274415020
Relay_Log_File: relay-bin.000253
Relay_Log_Pos: 175535154
Relay_Master_Log_File: binlog.000233
Slave_IO_Running: Yes
Slave_SQL_Running: No
.................:
Last_Errno: 1677
Last_Error: Column 28 of table 'test.test_tab_t1' cannot be converted from type 'varchar(30)(bytes))' to type 'varchar(400(bytes) gbk)'
Skip_Counter: 0
Exec_Master_Log_Pos: 175536357
Relay_Log_Space: 274410464
MySQL告警日志的報錯資訊:
2020-03-24T16:53:16.051244Z 11686 [ERROR] Slave SQL for channel '': Column 28 of table 'test.test_tab_t1' cannot be converted from type 'varchar(30(bytes))' to type 'varchar(400(bytes) gbk)', Error_code: 1677
2020-03-24T16:53:16.051269Z 11686 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'binlog.000233' position 175536357.
二、環境資訊
該項目目前使用的mysql社群版5.7.24,字元集為:gbk,binlog是ROW格式,采用的是keepalived+雙主(master-master)的架構。
mysql>select @@version,@@character_set_server,@@binlog_format;
+-----------+------------------------+-----------------+
| @@version | @@character_set_server | @@binlog_format |
+-----------+------------------------+-----------------+
| 5.7.24 | gbk | ROW |
+-----------+------------------------+-----------------+
三、診斷過程
1、根據MySQL Replication Breaks With Error 1677: Column .. of Table '...' Cannot Be Converted (Doc ID 2037712.1)文檔來看報錯資訊err1677分析來看test.test_tab_t1表的某個列(Column 28),出現了字元集相關的轉換錯誤。

首先對比(master1-master2)的字元集設定資訊:
之後對比(master1-master2)庫級,表級,列級的字元集資訊:
MASTER1 庫級,表級,列級的字元集資訊:
mysql>select * from information_schema.schemata where schema_name='test';
+--------------+-------------+----------------------------+------------------------+----------+--------------------+
| CATALOG_NAME | SCHEMA_NAME | DEFAULT_CHARACTER_SET_NAME | DEFAULT_COLLATION_NAME | SQL_PATH | DEFAULT_ENCRYPTION |
+--------------+-------------+----------------------------+------------------------+----------+--------------------+
| def | test | gbk | gbk_general_ci | NULL | NO |
+--------------+-------------+----------------------------+------------------------+----------+--------------------+
mysql>select table_schema,table_name,table_type,table_collation from information_schema.tables where table_name='test_tab_t1';
+--------------+------------+------------+-----------------+
| TABLE_SCHEMA | TABLE_NAME | TABLE_TYPE | TABLE_COLLATION |
+--------------+------------+------------+-----------------+
| test | test_tab_t1| BASE TABLE | gbk_chinese_ci |
+--------------+------------+------------+-----------------+
mysql>select table_name,column_name,character_maximum_length,character_octet_length,character_set_name,collation_name
from information_schema.columns where table_name='test_tab_t1' and table_schema='test' and ordinal_position=29;
+------------+-------------+--------------------------+------------------------+--------------------+----------------+
| TABLE_NAME | COLUMN_NAME | CHARACTER_MAXIMUM_LENGTH | CHARACTER_OCTET_LENGTH | CHARACTER_SET_NAME | COLLATION_NAME |
+------------+-------------+--------------------------+------------------------+--------------------+----------------+
| test_tab_t1| BXXX | 200 | 400 | gbk | gbk_chinese_ci |
+------------+-------------+--------------------------+------------------------+--------------------+----------------+
MASTER2 庫級,表級,列級的字元集資訊:
mysql>select * from information_schema.schemata where schema_name='test';
+--------------+-------------+----------------------------+------------------------+----------+--------------------+
| CATALOG_NAME | SCHEMA_NAME | DEFAULT_CHARACTER_SET_NAME | DEFAULT_COLLATION_NAME | SQL_PATH | DEFAULT_ENCRYPTION |
+--------------+-------------+----------------------------+------------------------+----------+--------------------+
| def | test | gbk | gbk_general_ci | NULL | NO |
+--------------+-------------+----------------------------+------------------------+----------+--------------------+
mysql>select table_schema,table_name,table_type,table_collation from information_schema.tables where table_name='test_tab_t1';
+--------------+------------+------------+-----------------+
| TABLE_SCHEMA | TABLE_NAME | TABLE_TYPE | TABLE_COLLATION |
+--------------+------------+------------+-----------------+
| test | test_tab_t1| BASE TABLE | gbk_chinese_ci |
+--------------+------------+------------+-----------------+
mysql>select table_name,column_name,character_maximum_length,character_octet_length,character_set_name,collation_name
from information_schema.columns where table_name='test_tab_t1' and table_schema='test' and ordinal_position=29;
+------------+-------------+--------------------------+------------------------+--------------------+----------------+
| TABLE_NAME | COLUMN_NAME | CHARACTER_MAXIMUM_LENGTH | CHARACTER_OCTET_LENGTH | CHARACTER_SET_NAME | COLLATION_NAME |
+------------+-------------+--------------------------+------------------------+--------------------+----------------+
| test_tab_t1| BXXX | 200 | 400 | gbk | gbk_chinese_ci |
+------------+-------------+--------------------------+------------------------+--------------------+----------------+
根據文檔((Doc ID 2037712.1)來看确實是系統更新變更表字段所對應的列(ALTER TABLE TEST.TEST_TAB_T1 MODIFY BXXX VARCHAR(200);)出現了問題。
報錯:Last_Error: Column 28 of table 'test.test_tab_t1' cannot be converted from type 'varchar(30(bytes))' to type 'varchar(400(bytes) gbk)
就是test.test_tab_t1表變更的字段bxxx(ordinal_position=29)在複制過程中出現了字元集問題,gbk的位元組大小是2,變更前bxxx确實是varchar(15)。
mysql> select * from information_schema.character_sets where character_set_name='gbk';
+--------------------+----------------------+------------------------+--------+
| CHARACTER_SET_NAME | DEFAULT_COLLATE_NAME | DESCRIPTION | MAXLEN |
+--------------------+----------------------+------------------------+--------+
| gbk | gbk_chinese_ci | GBK Simplified Chinese | 2 |
+--------------------+----------------------+------------------------+--------+
但對比了(master1-master2)庫級,表級,列級的字元集資訊是一緻的,不存在字元集不一緻的問題。這時感覺問題沒那麼簡單,接着往下分析。
我一開始想着是否是我們實施人員沒按規範來操作,因為是雙主環境,是否是在兩個執行個體同時執行了這個語句,排錯過程中發現/etc/my.cnf的client裡面character_set_client設定master1上是utf8,master2上是gbk。是以我們來看看發生故障的時間點binlog裡面的資訊,報錯是在binlog.000233,position為175536357時停止的。
mysqlbinlog --no-defaults --start-position=175536357 --database=test /opt/mysql/log/binlog/binlog.000233 --verbose
# at 175536357
#200325 0:53:16 server id 1 end_log_pos 175536422 CRC32 0xddd5d37 Anonymous_GTID last_committed=271185 sequence_number=27186 rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 175536422
#200325 0:53:16 server id 1 end_log_pos 175536505 CRC32 0x3799f3b Query thread_id=14154792 exec_time=0 error_code=0
SET TIMESTAMP=1585068796/*!*/;
SET @@session.pseudo_thread_id=14154792/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=2, @@session.auto_increment_offset=2/*!*/;
/*!\C gbk *//*!*/;
SET @@session.character_set_client=28,@@session.collation_connection=28,@@session.collation_server=28/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 175536505
#200325 0:53:16 server id 1 end_log_pos 175536685 CRC32 0xe3db6b6b Table_map: `test`.`test_tab_t1` mapped to number 23434
# at 175536685
#200325 0:53:16 server id 1 end_log_pos 175537481 CRC32 0xf1343123 Update_rows: table id 2334 flags: STMT_END_F
### UPDATE `test`.`test_tab_t1`
### WHERE
### @1='........'
### ..........
### @29='........'
### ..........
### @40='...'
### SET
### @1='........'
### ..........
### @29='........'
### ..........
### @40='...'
看到binlog裡面的SET @@session.character_set_client=28,@@session.collation_connection=28,@@session.collation_server=28 字元集确實是GBK
mysql> select * from information_schema.collations where id=28;
+----------------+--------------------+----+------------+-------------+---------+---------------+
| COLLATION_NAME | CHARACTER_SET_NAME | ID | IS_DEFAULT | IS_COMPILED | SORTLEN | PAD_ATTRIBUTE |
+----------------+--------------------+----+------------+-------------+---------+---------------+
| gbk_chinese_ci | gbk | 28 | Yes | Yes | 1 | PAD SPACE |
+----------------+--------------------+----+------------+-------------+---------+---------------+
1 row in set (0.01 sec)
以上足以肯定不是字元集不一緻的情況導緻。是以使用官方推薦的方法,設定參數slave_type_conversions=ALL_LOSSY/ALL_NON_LOSSY來解決是無效的,而且該方法還存在資料轉換丢失的風險。
另外根據https://bugs.mysql.com/bug.php?id=83461也描述了某個字段字元集不一緻的主從複制報err1677錯誤的問題,同時還提到另外一個情況,binlog_format=ROW時,因為解析中繼日志時出現解析問題,可以考慮把binlog_format=MIXED格式,嘗試拉起slave也是無法拉起的。
分析到這,感覺沒有了思路,繼續查找資料吧,有時就這樣,山窮水複疑無路,柳暗花明又一村。終于找到一個很有代表性的參考資料:https://bugs.mysql.com/bug.php?id=88595,這個是在5.6.37上的Bug #88595,Row-based master-master replication broken by add column or drop column。但該項目的環境是5.7.24,架構都是binlog_format=ROW的雙主。
通過以上資訊對比我貼出的binlog資訊,确實中斷的時間點存在update test.test_tab_t1表的情況。這裡就說的通,雖然版本不一緻,但根據故障現象是幾乎接近的。
ALGORITHM=INPLACE (Default)情況下:
master1執行了:ALTER TABLE TEST.TEST_TAB_T1 MODIFY BXXX VARCHAR(200);按記錄在binlog裡,
master2通過拉取binlog進行同步變更字段資訊的語句,在運作過程中,master2同時存在update test.test_tab_t1表的情況(比變更的字段語句先完成)
master1在進行同步update test.test_tab_t1表的語句時,因為已經變更了字段,表結構發生了變化,而update語句還是原結構的資訊,是以就出現了err1677的報錯 。
以上基本說的通了,不過這裡還有2個疑問,1個是這個業務不是配置的雙寫,隻寫其中一個執行個體,唯一可解釋的就是,實施同僚是在非寫執行個體上(master1)進行的DDL動作。還有1個就是版本問題,後來也咨詢了項目實施同僚,該資料庫是由5.6基礎上更新而來。難到...?難到是更新後會有遺留問題?目前能力有限,先記錄下來,後續再更深入分析。
四、解決辦法
這裡的解決方法對我這個情況來說沒有參考性,而且經過上述分析,及根據該表的業務情況,決定先跳過該錯誤,後檢驗資料一緻性。
stop slave;
-- 表示跳過一步錯誤,後面的數字可變,1表示跳過1步
set global sql_slave_skip_counter = 1;
start slave;
# pt-table-checksum可以用來檢測master1-master2資料庫test中的test_tab_t1表的資料一緻性,如果存在不一緻在使用該工具進行修複。
pt-table-checksum --nocheck-replication-filters --databases=test --replicate=test.test_tab_t1 --create-replicate-table --host=xxx --port 3306 -uroot -pxxx
五、故障總結
以上的故障分析和解決故障的過程,發現的這個BUG,讓我覺得這個跟oracle goldengate隻複制DML,源端表進行了DDL變更的OGG-01161及OGG-01163很相似。
網上很多OGG-01161,OGG-01163源端表結構發生變化導緻replicat程序abend的文章,都提到對比源端和目标端的表結構一緻,重新開機R程序還是報錯。
雖然源端和目标端該字段的長度已修改,且def檔案也都已修改,但生成的trail檔案中的meta資訊并不會更新。replicat程序預設按照trail檔案中的meta資訊進行操作。是以還是報錯。需要加OVERRIDE選項,新的def内容才能覆寫trail中的meta資訊。