〇 現象：
    在透過binlog增量恢復資料時，報錯1050。
〇版本：
    MySQL 5.5.x 及以下，低版本的MySQL 5.6.x （在5.6的高版本中測試，無法復現，疑似被修復）
〇原因：
    binlog記錄了執行出錯的DDL語句，此處，具體DDL是CREATE VIEW $view_name AS ...

有點奇怪，難道執行錯誤了的DDL也會被記錄到binlog中麼？

〇復現：

[17:52:45] root@localhost [a]> FLUSH LOGS;
Query OK, 0 rows affected (0.01 sec)
[17:52:47] root@localhost [a]> SHOW BINLOG EVENTS IN 'mysql55-bin.000006';
+--------------------+-----+-------------+-----------+-------------+---------------------------------------+
| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
+--------------------+-----+-------------+-----------+-------------+---------------------------------------+
| mysql55-bin.000006 | 4 | Format_desc | 55 | 107 | Server ver: 5.5.57-log, Binlog ver: 4 |
+--------------------+-----+-------------+-----------+-------------+---------------------------------------+
1 row in set (0.00 sec)
[17:53:13] root@localhost [a]> CREATE TABLE t(id int);
Query OK, 0 rows affected (0.01 sec)
[17:53:18] root@localhost [a]> CREATE VIEW v_t AS SELECT * from t;
Query OK, 0 rows affected (0.00 sec)
[17:53:21] root@localhost [a]> CREATE VIEW v_t AS SELECT * from t;
ERROR 1050 (42S01): Table 'v_t' already exists

此時，再次檢查binlog：

[17:53:24] root@localhost [a]> SHOW BINLOG EVENTS IN 'mysql55-bin.000006'\G
*************************** 1. row ***************************
Log_name: mysql55-bin.000006
Pos: 4
Event_type: Format_desc
Server_id: 55
End_log_pos: 107
Info: Server ver: 5.5.57-log, Binlog ver: 4
*************************** 2. row ***************************
Log_name: mysql55-bin.000006
Pos: 107
Event_type: Query
Server_id: 55
End_log_pos: 189
Info: use `a`; CREATE TABLE t(id int)
*************************** 3. row ***************************
Log_name: mysql55-bin.000006
Pos: 189
Event_type: Query
Server_id: 55
End_log_pos: 369
Info: use `a`; CREATE ALGORITHM=UNDEFINED DEFINER=`root`@`localhost` SQL SECURITY DEFINER VIEW `v_t` AS SELECT * from t
*************************** 4. row ***************************
Log_name: mysql55-bin.000006
Pos: 369
Event_type: Query
Server_id: 55
End_log_pos: 549
Info: use `a`; CREATE ALGORITHM=UNDEFINED DEFINER=`root`@`localhost` SQL SECURITY DEFINER VIEW `v_t` AS SELECT * from t
4 rows in set (0.00 sec)

可以發現，第二次執行CREATE VIEW，即便在mysql client執行時報錯，也被記錄到binlog中。
自然，在透過mysqlbinlog重放binlog時，也會報錯。

但在複製結構中，從例項不會重放該events，故從庫不會報錯。

重新透過mysqlbinlog解析日誌得到：

# at 107
#180206 17:53:18 server id 55 end_log_pos 189 Query thread_id=13 exec_time=0 error_code=0
use `a`/*!*/;
SET TIMESTAMP=1517910798/*!*/;
SET @@session.pseudo_thread_id=13/*!*/;
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=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
CREATE TABLE t(id int)
/*!*/;
# at 189
#180206 17:53:21 server id 55 end_log_pos 369 Query thread_id=13 exec_time=0 error_code=0
SET TIMESTAMP=1517910801/*!*/;
CREATE ALGORITHM=UNDEFINED DEFINER=`root`@`localhost` SQL SECURITY DEFINER VIEW `v_t` AS SELECT * from t
/*!*/;
# at 369
#180206 17:53:22 server id 55 end_log_pos 549 Query thread_id=13 exec_time=0 error_code=1050
SET TIMESTAMP=1517910802/*!*/;
CREATE ALGORITHM=UNDEFINED DEFINER=`root`@`localhost` SQL SECURITY DEFINER VIEW `v_t` AS SELECT * from t
/*!*/;

可以發現第二次報錯的語句，雖然被記錄到binlog中，但error_code標識為1050

至於為何從庫不報錯，大概是因為sql thread會特殊處理這種error_code，不會執行。
而mysqlbinlog mysql-binlog.00000x | mysql -u -p -S 重放binlog的方式會報錯。——大概是因為mysql這個client工具沒有做對mysqlbinlog解析出來的error_code的特殊處理吧。

暫時不知道是否為bug，但高版本的MySQL5.6.x已經修正了該問題，5.7也如此。

因此，在可能出現問題的版本，透過binlog增量恢復資料時，可能需要特殊處理。

【MySQL】重放binlog故障一則 ERROR 1050 (42S01) : Table '' already exists

相關文章