Software Engineering via anthonymcgowan1 on Inoreader
How To Fix MySQL Replication After an Incompatible DDL Command
fix MySQL replication after incompatible DDL

fix MySQL replication after incompatible DDLMySQL 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. :

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. 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:

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:

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:

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

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.

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:

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.

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: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:

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:

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:

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.

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.

The post How To Fix MySQL Replication After an Incompatible DDL Command appeared first on Percona Database Performance Blog.

Leave a Reply

Your email address will not be published. Required fields are marked *