How To Fix MySQL Replication After an Incompatible DDL Command
MySQL supports replicating to a slave that is one release higher. This allows us to easily upgrade our MySQL setup to a new version, by promoting the slave and pointing the application to it. However, though unsupported, there are times when the MySQL version of slave deployed is one release lower. In this scenario, if your application has been performing much better on an older version of MySQL, you would like to have a convenient option to downgrade. You can simply promote the slave to get the old performance back.
The MySQL manual says that ROW based replication can be used to replicate to a lower version, provided that no DDLs replicated are incompatible with the slave. One such incompatible command is ALTER USER which is a new feature in MySQL 5.7 and not available on 5.6. :
|
1 |
ALTER USER 'testuser'@'localhost' IDENTIFIED BY 'testuser'; |
Executing that command would break replication. Here is an example of a broken slave in non-GTID replication:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 |
*************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: repl Master_Port: 5723 Connect_Retry: 60 Master_Log_File: mysql-bin.000002 Read_Master_Log_Pos: 36915649 Relay_Log_File: mysql_sandbox5641-relay-bin.000006 Relay_Log_Pos: 36174552 Relay_Master_Log_File: mysql-bin.000002 Slave_IO_Running: Yes Slave_SQL_Running: No *** redacted *** Last_Errno: 1064 Last_Error: Error 'You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'IDENTIFIED WITH 'mysql_native_password' AS '*3A2EB9C80F7239A4DE3933AE266DB76A784' at line 1' on query. Default database: ''. Query: 'ALTER USER 'testuser'@'localhost' IDENTIFIED WITH 'mysql_native_password' AS '*3A2EB9C80F7239A4DE3933AE266DB76A7846BCB8'' Skip_Counter: 0 Exec_Master_Log_Pos: 36174373 Relay_Log_Space: 36916179 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No *** redacted *** Seconds_Behind_Master: NULL Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 1064 Last_SQL_Error: Error 'You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'IDENTIFIED WITH 'mysql_native_password' AS '*3A2EB9C80F7239A4DE3933AE266DB76A784' at line 1' on query. Default database: ''. Query: 'ALTER USER 'testuser'@'localhost' IDENTIFIED WITH 'mysql_native_password' AS '*3A2EB9C80F7239A4DE3933AE266DB76A7846BCB8'' Replicate_Ignore_Server_Ids: Master_Server_Id: 1 Master_UUID: 00005723-0000-0000-0000-000000005723 *** redacted *** Last_IO_Error_Timestamp: Last_SQL_Error_Timestamp: 180918 22:03:40 *** redacted *** Auto_Position: 0 1 row in set (0.00 sec) |
Skipping the statement does not resume replication:
|
1 2 3 4 5 6 7 |
mysql> STOP SLAVE; Query OK, 0 rows affected (0.02 sec) mysql> SET GLOBAL sql_slave_skip_counter=1; Query OK, 0 rows affected (0.00 sec) mysql> START SLAVE; Query OK, 0 rows affected (0.01 sec) mysql> SHOW SLAVE STATUS\G |
Fixing non-GTID replication
When you check slave status, replication still isn’t fixed. To fix it, you must manually skip to the next binary log position. The current binary log (Relay_Master_Log_File) and position (Exec_Master_Log_Pos) executed are mysql-bin.000002 and 36174373 respectively. We can use mysqlbinlog on the master to determine the next position:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 |
mysqlbinlog -v --base64-output=DECODE-ROWS --start-position=36174373 /ssd/sandboxes/msb_5_7_23/data/mysql-bin.000002 | head -n 30 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 36174373 #180918 22:03:40 server id 1 end_log_pos 36174438 CRC32 0xc7e1e553 Anonymous_GTID last_committed=19273 sequence_number=19277 rbr_only=no SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 36174438 #180918 22:03:40 server id 1 end_log_pos 36174621 CRC32 0x2e5bb235 Query thread_id=563 exec_time=0 error_code=0 SET TIMESTAMP=1537279420/*!*/; SET @@session.pseudo_thread_id=563/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1436549152/*!*/; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; /*!\C latin1 *//*!*/; SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/; SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/; ALTER USER 'testuser'@'localhost' IDENTIFIED WITH 'mysql_native_password' AS '*3A2EB9C80F7239A4DE3933AE266DB76A7846BCB8' /*!*/; # at 36174621 #180918 22:03:40 server id 1 end_log_pos 36174686 CRC32 0x86756b3f Anonymous_GTID last_committed=19275 sequence_number=19278 rbr_only=yes /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/; SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 36174686 #180918 22:03:40 server id 1 end_log_pos 36174760 CRC32 0x30e663f9 Query thread_id=529 exec_time=0 error_code=0 SET TIMESTAMP=1537279420/*!*/; BEGIN /*!*/; # at 36174760 #180918 22:03:40 server id 1 end_log_pos 36174819 CRC32 0x48054daf Table_map: `sbtest`.`sbtest1` mapped to number 226 |
Based on the output above, the next binary log position is 36174621. To fix the slave, run:
|
1 2 3 |
STOP SLAVE; CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000002', MASTER_LOG_POS=36174621; START SLAVE; |
Verify if the slave threads are now running by executing SHOW SLAVE STATUS\G
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 |
Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: repl Master_Port: 5723 Connect_Retry: 60 Master_Log_File: mysql-bin.000002 Read_Master_Log_Pos: 306841423 Relay_Log_File: mysql_sandbox5641-relay-bin.000002 Relay_Log_Pos: 190785290 Relay_Master_Log_File: mysql-bin.000002 Slave_IO_Running: Yes Slave_SQL_Running: Yes *** redacted *** Last_Errno: 0 Last_Error: Skip_Counter: 0 Exec_Master_Log_Pos: 226959625 Relay_Log_Space: 270667273 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No *** redacted *** Seconds_Behind_Master: 383 Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 0 Last_SQL_Error: Replicate_Ignore_Server_Ids: Master_Server_Id: 1 Master_UUID: 00005723-0000-0000-0000-000000005723 Master_Info_File: /ssd/sandboxes/msb_5_6_41/data/master.info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Opening tables Master_Retry_Count: 86400 *** redacted *** Auto_Position: 0 |
To make the slave consistent with the master, execute the compatible query on the slave.
|
1 2 |
SET SESSION sql_log_bin = 0; GRANT USAGE ON *.* TO 'testuser'@'localhost' IDENTIFIED BY 'testuser'; |
Done.
GTID replication
For GTID replication, in addition to injecting an empty transaction for the offending statement, you’ll need skip it by using the non-GTID solution provided above. Once running, flip it back to GTID.
Here’s an example of a broken GTID slave:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 |
mysql> SHOW SLAVE STATUS\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: repl Master_Port: 5723 Connect_Retry: 60 Master_Log_File: mysql-bin.000003 Read_Master_Log_Pos: 14364967 Relay_Log_File: mysql_sandbox5641-relay-bin.000002 Relay_Log_Pos: 8630318 Relay_Master_Log_File: mysql-bin.000003 Slave_IO_Running: Yes Slave_SQL_Running: No *** redacted *** Last_Errno: 1064 Last_Error: Error 'You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'IDENTIFIED WITH 'mysql_native_password' AS '*3A2EB9C80F7239A4DE3933AE266DB76A784' at line 1' on query. Default database: ''. Query: 'ALTER USER 'testuser'@'localhost' IDENTIFIED WITH 'mysql_native_password' AS '*3A2EB9C80F7239A4DE3933AE266DB76A7846BCB8'' Skip_Counter: 0 Exec_Master_Log_Pos: 12468343 Relay_Log_Space: 10527158 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No *** redacted *** Seconds_Behind_Master: NULL Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 1064 Last_SQL_Error: Error 'You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'IDENTIFIED WITH 'mysql_native_password' AS '*3A2EB9C80F7239A4DE3933AE266DB76A784' at line 1' on query. Default database: ''. Query: 'ALTER USER 'testuser'@'localhost' IDENTIFIED WITH 'mysql_native_password' AS '*3A2EB9C80F7239A4DE3933AE266DB76A7846BCB8'' Replicate_Ignore_Server_Ids: Master_Server_Id: 1 Master_UUID: 00005723-0000-0000-0000-000000005723 Master_Info_File: /ssd/sandboxes/msb_5_6_41/data/master.info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Master_Retry_Count: 86400 Master_Bind: Last_IO_Error_Timestamp: Last_SQL_Error_Timestamp: 180918 22:32:28 Master_SSL_Crl: Master_SSL_Crlpath: Retrieved_Gtid_Set: 00005723-0000-0000-0000-000000005723:2280-8530 Executed_Gtid_Set: 00005723-0000-0000-0000-000000005723:1-7403 Auto_Position: 1 1 row in set (0.00 sec) mysql> SHOW GLOBAL VARIABLES LIKE 'gtid_executed'; +---------------+---------------------------------------------+ | Variable_name | Value | +---------------+---------------------------------------------+ | gtid_executed | 00005723-0000-0000-0000-000000005723:1-7403 | +---------------+---------------------------------------------+ 1 row in set (0.00 sec) |
Since the last position executed is 7403, so you’ll need to create an empty transaction for the offending sequence 7404.
|
1 2 3 4 5 6 |
STOP SLAVE; SET GTID_NEXT='00005723-0000-0000-0000-000000005723:7404'; BEGIN; COMMIT; SET GTID_NEXT=AUTOMATIC; START SLAVE; |
Note: If you have MTS enabled, you can also get the offending GTID coordinates from Last_SQL_Error of SHOW SLAVE STATUS\G
The next step is to find the next binary log position. The current binary log(Relay_Master_Log_File) and position(Exec_Master_Log_Pos) executed are mysql-bin.000003 and 12468343 respectively. We can again use mysqlbinlog on the master to determine the next position:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 |
mysqlbinlog -v --base64-output=DECODE-ROWS --start-position=12468343 /ssd/sandboxes/msb_5_7_23/data/mysql-bin.000003 | head -n 30 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 12468343 #180918 22:32:19 server id 1 end_log_pos 12468408 CRC32 0x259ee085 GTID last_committed=7400 sequence_number=7404 rbr_only=no SET @@SESSION.GTID_NEXT= '00005723-0000-0000-0000-000000005723:7404'/*!*/; # at 12468408 #180918 22:32:19 server id 1 end_log_pos 12468591 CRC32 0xb349ad80 Query thread_id=142 exec_time=0 error_code=0 SET TIMESTAMP=1537281139/*!*/; SET @@session.pseudo_thread_id=142/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1436549152/*!*/; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; /*!\C latin1 *//*!*/; SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/; SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/; ALTER USER 'testuser'@'localhost' IDENTIFIED WITH 'mysql_native_password' AS '*3A2EB9C80F7239A4DE3933AE266DB76A7846BCB8' /*!*/; # at 12468591 #180918 22:32:19 server id 1 end_log_pos 12468656 CRC32 0xb2019f3f GTID last_committed=7400 sequence_number=7405 rbr_only=yes /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/; SET @@SESSION.GTID_NEXT= '00005723-0000-0000-0000-000000005723:7405'/*!*/; # at 12468656 #180918 22:32:19 server id 1 end_log_pos 12468730 CRC32 0x76b5ea6c Query thread_id=97 exec_time=0 error_code=0 SET TIMESTAMP=1537281139/*!*/; BEGIN /*!*/; # at 12468730 #180918 22:32:19 server id 1 end_log_pos 12468789 CRC32 0x48f0ba6d Table_map: `sbtest`.`sbtest8` mapped to number 115 |
The next binary log position is 36174621. To fix the slave, run:
|
1 2 3 |
STOP SLAVE; CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000003', MASTER_LOG_POS=12468591, MASTER_AUTO_POSITION=0; START SLAVE; |
Notice that I added MASTER_AUTO_POSITION=0 above to disable GTID replication for now. You can run SHOW SLAVE STATUS\G to determine that MySQL is running fine:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 |
mysql> SHOW SLAVE STATUS\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: repl Master_Port: 5723 Connect_Retry: 60 Master_Log_File: mysql-bin.000003 Read_Master_Log_Pos: 446194575 Relay_Log_File: mysql_sandbox5641-relay-bin.000002 Relay_Log_Pos: 12704248 Relay_Master_Log_File: mysql-bin.000003 Slave_IO_Running: Yes Slave_SQL_Running: Yes *** redacted *** Last_Errno: 0 Last_Error: Skip_Counter: 0 Exec_Master_Log_Pos: 25172522 Relay_Log_Space: 433726939 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No *** redacted *** Seconds_Behind_Master: 2018 Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 0 Last_SQL_Error: Replicate_Ignore_Server_Ids: Master_Server_Id: 1 Master_UUID: 00005723-0000-0000-0000-000000005723 Master_Info_File: /ssd/sandboxes/msb_5_6_41/data/master.info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Reading event from the relay log Master_Retry_Count: 86400 *** redacted *** Retrieved_Gtid_Set: 00005723-0000-0000-0000-000000005723:7405-264930 Executed_Gtid_Set: 00005723-0000-0000-0000-000000005723:1-14947 Auto_Position: 0 |
Since it’s running fine you can now revert back to GTID replication:
|
1 2 3 |
STOP SLAVE; CHANGE MASTER TO MASTER_AUTO_POSITION=1; START SLAVE; |
Finally, to make the slave consistent with the master, execute the compatible query on the slave.
|
1 2 |
SET SESSION sql_log_bin = 0; GRANT USAGE ON *.* TO 'testuser'@'localhost' IDENTIFIED BY 'testuser'; |
Summary
In this article, I’ve shared how to fix replication when it breaks due to an incompatible command being replicated to the slave. In fact, I’ve only identified ALTER USER as an incompatible command for 5.6. If there are other incompatible commands, please share them in the comment section. Thanks in advance.
Update:
I filed a bug at https://bugs.mysql.com/bug.php?id=92629 to verify if the errors I’ve encountered here is a bug or undocumented behavior.
Comment (1)
Great article. Thank you!