Bug #97027 | Bulk insert with ON DUPLICATE KEY UPDATE breaks replicaiton | ||
---|---|---|---|
Submitted: | 26 Sep 2019 10:02 | Modified: | 15 Jan 2021 16:20 |
Reporter: | Christian Roser | Email Updates: | |
Status: | Verified | Impact on me: | |
Category: | MySQL Server: Row Based Replication ( RBR ) | Severity: | S2 (Serious) |
Version: | 5.7.* | OS: | Any |
Assigned to: | CPU Architecture: | x86 | |
Tags: | bulk, RBR, regression |
[26 Sep 2019 10:02]
Christian Roser
[26 Sep 2019 10:04]
Christian Roser
sql file to break replication
Attachment: break_replication.sql (application/sql, text), 95 bytes.
[26 Sep 2019 10:04]
Christian Roser
file to initialize test database
Attachment: db.sql (application/sql, text), 1.87 KiB.
[8 Oct 2019 15:13]
MySQL Verification Team
5.7.27 to 5.7.27 works ok master [localhost:19428] {root} (test) > CREATE TABLE `t1` ( -> `id` int(11) DEFAULT NULL, -> `test` varchar(255) DEFAULT 'hallo', -> UNIQUE KEY `id` (`id`) -> ) ENGINE=InnoDB DEFAULT CHARSET=utf8; Query OK, 0 rows affected (0.01 sec) master [localhost:19428] {root} (test) > INSERT INTO `t1` VALUES (1,'foo'),(2,'test'),(3,'lorem'); Query OK, 3 rows affected (0.02 sec) Records: 3 Duplicates: 0 Warnings: 0 master [localhost:19428] {root} (test) > insert into t1 values(1, 'test'), (1, 'bar') on duplicate key update test=values(test); Query OK, 4 rows affected (0.01 sec) Records: 2 Duplicates: 2 Warnings: 0 master [localhost:19428] {root} (test) > --- slave1 [localhost:19429] {msandbox} (test) > select * from t1; +------+-------+ | id | test | +------+-------+ | 1 | foo | | 2 | test | | 3 | lorem | +------+-------+ 3 rows in set (0.00 sec) slave1 [localhost:19429] {msandbox} (test) > select * from t1; +------+-------+ | id | test | +------+-------+ | 1 | bar | | 2 | test | | 3 | lorem | +------+-------+ 3 rows in set (0.00 sec) slave1 [localhost:19429] {msandbox} (test) > show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: rsandbox Master_Port: 19428 Connect_Retry: 60 Master_Log_File: mysql-bin.000001 Read_Master_Log_Pos: 4955 Relay_Log_File: mysql-relay.000002 Relay_Log_Pos: 5168 Relay_Master_Log_File: mysql-bin.000001 Slave_IO_Running: Yes Slave_SQL_Running: Yes Replicate_Do_DB: Replicate_Ignore_DB: Replicate_Do_Table: Replicate_Ignore_Table: Replicate_Wild_Do_Table: Replicate_Wild_Ignore_Table: Last_Errno: 0 Last_Error: Skip_Counter: 0 Exec_Master_Log_Pos: 4955 Relay_Log_Space: 5371 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No Master_SSL_CA_File: Master_SSL_CA_Path: Master_SSL_Cert: Master_SSL_Cipher: Master_SSL_Key: Seconds_Behind_Master: 0 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: 100 Master_UUID: 00019428-1111-1111-1111-111111111111 Master_Info_File: /home/arhimed/sandboxes/rsandbox_5_7_27/node1/data/master.info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates Master_Retry_Count: 86400 Master_Bind: Last_IO_Error_Timestamp: Last_SQL_Error_Timestamp: Master_SSL_Crl: Master_SSL_Crlpath: Retrieved_Gtid_Set: Executed_Gtid_Set: Auto_Position: 0 Replicate_Rewrite_DB: Channel_Name: Master_TLS_Version: 1 row in set (0.00 sec) slave1 [localhost:19429] {msandbox} (test) >
[8 Oct 2019 15:24]
MySQL Verification Team
5.6.44 to 5.7.27 - works 5.6.44 to 8.0.17 - works mysql [localhost:5645] {root} (test) > CREATE TABLE `t1` ( -> `id` int(11) DEFAULT NULL, -> `test` varchar(255) DEFAULT 'hallo', -> UNIQUE KEY `id` (`id`) -> ) ENGINE=InnoDB DEFAULT CHARSET=utf8; Query OK, 0 rows affected (0.01 sec) mysql [localhost:5645] {root} (test) > INSERT INTO `t1` VALUES (1,'foo'),(2,'test'),(3,'lorem'); Query OK, 3 rows affected (0.00 sec) Records: 3 Duplicates: 0 Warnings: 0 mysql [localhost:5645] {root} (test) > insert into t1 values(1, 'test'), (1, 'bar') on duplicate key update test=values(test); Query OK, 4 rows affected (0.04 sec) Records: 2 Duplicates: 2 Warnings: 0 mysql [localhost:5645] {msandbox} ((none)) > select @@version -> ; +------------+ | @@version | +------------+ | 5.6.44-log | +------------+ 1 row in set (0.00 sec) ----- mysql [localhost:5728] {msandbox} (test) > select @@version; +------------+ | @@version | +------------+ | 5.7.27-log | +------------+ 1 row in set (0.00 sec) mysql [localhost:5728] {msandbox} (test) > show tables; +----------------+ | Tables_in_test | +----------------+ | t1 | +----------------+ 1 row in set (0.00 sec) mysql [localhost:5728] {msandbox} (test) > select * from t1; +------+-------+ | id | test | +------+-------+ | 1 | foo | | 2 | test | | 3 | lorem | +------+-------+ 3 rows in set (0.00 sec) mysql [localhost:5728] {msandbox} (test) > select * from t1; +------+-------+ | id | test | +------+-------+ | 1 | bar | | 2 | test | | 3 | lorem | +------+-------+ 3 rows in set (0.00 sec) mysql [localhost:5728] {msandbox} (test) > show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: rsandbox Master_Port: 5645 Connect_Retry: 60 Master_Log_File: mysql-bin.000001 Read_Master_Log_Pos: 3946 Relay_Log_File: mysql-relay.000002 Relay_Log_Pos: 1565 Relay_Master_Log_File: mysql-bin.000001 Slave_IO_Running: Yes Slave_SQL_Running: Yes Replicate_Do_DB: Replicate_Ignore_DB: Replicate_Do_Table: Replicate_Ignore_Table: Replicate_Wild_Do_Table: Replicate_Wild_Ignore_Table: Last_Errno: 0 Last_Error: Skip_Counter: 0 Exec_Master_Log_Pos: 3946 Relay_Log_Space: 1768 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No Master_SSL_CA_File: Master_SSL_CA_Path: Master_SSL_Cert: Master_SSL_Cipher: Master_SSL_Key: Seconds_Behind_Master: 0 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: 5644 Master_UUID: 00005645-0000-0000-0000-000000005645 Master_Info_File: /home/arhimed/sandboxes/mv_slave1/data/master.info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates Master_Retry_Count: 86400 Master_Bind: Last_IO_Error_Timestamp: Last_SQL_Error_Timestamp: Master_SSL_Crl: Master_SSL_Crlpath: Retrieved_Gtid_Set: Executed_Gtid_Set: Auto_Position: 0 Replicate_Rewrite_DB: Channel_Name: Master_TLS_Version: 1 row in set (0.00 sec) mysql [localhost:5728] {msandbox} (test) >
[8 Oct 2019 15:25]
MySQL Verification Team
mysql [localhost:8018] {msandbox} (test) > select @@version; +-----------+ | @@version | +-----------+ | 8.0.17 | +-----------+ 1 row in set (0.00 sec) mysql [localhost:8018] {msandbox} (test) > show tables; +----------------+ | Tables_in_test | +----------------+ | t1 | +----------------+ 1 row in set (0.00 sec) mysql [localhost:8018] {msandbox} (test) > select * from t1; +------+-------+ | id | test | +------+-------+ | 1 | foo | | 2 | test | | 3 | lorem | +------+-------+ 3 rows in set (0.00 sec) mysql [localhost:8018] {msandbox} (test) > select * from t1; +------+-------+ | id | test | +------+-------+ | 1 | bar | | 2 | test | | 3 | lorem | +------+-------+ 3 rows in set (0.00 sec) mysql [localhost:8018] {msandbox} (test) > show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: rsandbox Master_Port: 5645 Connect_Retry: 60 Master_Log_File: mysql-bin.000001 Read_Master_Log_Pos: 3946 Relay_Log_File: mysql-relay.000002 Relay_Log_Pos: 1566 Relay_Master_Log_File: mysql-bin.000001 Slave_IO_Running: Yes Slave_SQL_Running: Yes Replicate_Do_DB: Replicate_Ignore_DB: Replicate_Do_Table: Replicate_Ignore_Table: Replicate_Wild_Do_Table: Replicate_Wild_Ignore_Table: Last_Errno: 0 Last_Error: Skip_Counter: 0 Exec_Master_Log_Pos: 3946 Relay_Log_Space: 1770 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No Master_SSL_CA_File: Master_SSL_CA_Path: Master_SSL_Cert: Master_SSL_Cipher: Master_SSL_Key: Seconds_Behind_Master: 0 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: 5644 Master_UUID: 00005645-0000-0000-0000-000000005645 Master_Info_File: mysql.slave_master_info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates Master_Retry_Count: 86400 Master_Bind: Last_IO_Error_Timestamp: Last_SQL_Error_Timestamp: Master_SSL_Crl: Master_SSL_Crlpath: Retrieved_Gtid_Set: Executed_Gtid_Set: Auto_Position: 0 Replicate_Rewrite_DB: Channel_Name: Master_TLS_Version: Master_public_key_path: Get_master_public_key: 0 Network_Namespace: 1 row in set (0.00 sec) mysql [localhost:8018] {msandbox} (test) >
[8 Oct 2019 15:26]
MySQL Verification Team
Hi, I cannot reproduce your test case. Please make sure you are using LATEST versions of all servers you are replicating from/to when you cross major version ... so from 5.6.xx to 5.7.xx please first upgrade 5.6 to latest and replicate to latest 5.7 .. same for 8.0.xx thanks
[8 Oct 2019 15:39]
MySQL Verification Team
tested with 5.5.62 as a master too, works ok mysql [localhost:5562] {root} (test) > show variables like 'version'; +---------------+------------+ | Variable_name | Value | +---------------+------------+ | version | 5.5.62-log | +---------------+------------+ 1 row in set (0.00 sec) mysql [localhost:5562] {root} (test) > CREATE TABLE `t1` ( -> `id` int(11) DEFAULT NULL, -> `test` varchar(255) DEFAULT 'hallo', -> UNIQUE KEY `id` (`id`) -> ) ENGINE=InnoDB DEFAULT CHARSET=utf8; Query OK, 0 rows affected (0.00 sec) mysql [localhost:5562] {root} (test) > INSERT INTO `t1` VALUES (1,'foo'),(2,'test'),(3,'lorem'); Query OK, 3 rows affected (0.01 sec) Records: 3 Duplicates: 0 Warnings: 0 mysql [localhost:5562] {root} (test) > insert into t1 values(1, 'test'), (1, 'bar') on duplicate key update test=values(test); Query OK, 4 rows affected (0.01 sec) Records: 2 Duplicates: 2 Warnings: 0 mysql [localhost:5562] {root} (test) > ---- mysql [localhost:5728] {msandbox} (test) > select * from t1; +------+-------+ | id | test | +------+-------+ | 1 | bar | | 2 | test | | 3 | lorem | +------+-------+ 3 rows in set (0.00 sec) mysql [localhost:5728] {msandbox} (test) > show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: rsandbox Master_Port: 5562 Connect_Retry: 60 Master_Log_File: mysql-bin.000001 Read_Master_Log_Pos: 3843 Relay_Log_File: mysql-relay.000002 Relay_Log_Pos: 1971 Relay_Master_Log_File: mysql-bin.000001 Slave_IO_Running: Yes Slave_SQL_Running: Yes Replicate_Do_DB: Replicate_Ignore_DB: Replicate_Do_Table: Replicate_Ignore_Table: Replicate_Wild_Do_Table: Replicate_Wild_Ignore_Table: Last_Errno: 0 Last_Error: Skip_Counter: 0 Exec_Master_Log_Pos: 3843 Relay_Log_Space: 2174 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No Master_SSL_CA_File: Master_SSL_CA_Path: Master_SSL_Cert: Master_SSL_Cipher: Master_SSL_Key: Seconds_Behind_Master: 0 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: 5562 Master_UUID: Master_Info_File: /home/arhimed/sandboxes/mv_slave1/data/master.info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates Master_Retry_Count: 86400 Master_Bind: Last_IO_Error_Timestamp: Last_SQL_Error_Timestamp: Master_SSL_Crl: Master_SSL_Crlpath: Retrieved_Gtid_Set: Executed_Gtid_Set: Auto_Position: 0 Replicate_Rewrite_DB: Channel_Name: Master_TLS_Version: 1 row in set (0.00 sec) mysql [localhost:5728] {msandbox} (test) > select @@version; +------------+ | @@version | +------------+ | 5.7.27-log | +------------+ 1 row in set (0.00 sec) mysql [localhost:5728] {msandbox} (test) >
[8 Oct 2019 15:39]
MySQL Verification Team
mysql [localhost:8018] {msandbox} (test) > select * from t1; +------+-------+ | id | test | +------+-------+ | 1 | bar | | 2 | test | | 3 | lorem | +------+-------+ 3 rows in set (0.00 sec) mysql [localhost:8018] {msandbox} (test) > show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: rsandbox Master_Port: 5562 Connect_Retry: 60 Master_Log_File: mysql-bin.000001 Read_Master_Log_Pos: 3843 Relay_Log_File: mysql-relay.000002 Relay_Log_Pos: 1972 Relay_Master_Log_File: mysql-bin.000001 Slave_IO_Running: Yes Slave_SQL_Running: Yes Replicate_Do_DB: Replicate_Ignore_DB: Replicate_Do_Table: Replicate_Ignore_Table: Replicate_Wild_Do_Table: Replicate_Wild_Ignore_Table: Last_Errno: 0 Last_Error: Skip_Counter: 0 Exec_Master_Log_Pos: 3843 Relay_Log_Space: 2176 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No Master_SSL_CA_File: Master_SSL_CA_Path: Master_SSL_Cert: Master_SSL_Cipher: Master_SSL_Key: Seconds_Behind_Master: 0 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: 5562 Master_UUID: Master_Info_File: mysql.slave_master_info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates Master_Retry_Count: 86400 Master_Bind: Last_IO_Error_Timestamp: Last_SQL_Error_Timestamp: Master_SSL_Crl: Master_SSL_Crlpath: Retrieved_Gtid_Set: Executed_Gtid_Set: Auto_Position: 0 Replicate_Rewrite_DB: Channel_Name: Master_TLS_Version: Master_public_key_path: Get_master_public_key: 0 Network_Namespace: 1 row in set (0.00 sec) mysql [localhost:8018] {msandbox} (test) > select @@version -> ; +-----------+ | @@version | +-----------+ | 8.0.17 | +-----------+ 1 row in set (0.00 sec)
[8 Oct 2019 17:25]
Christian Roser
I managed to find the causing mysql setting: slave_rows_search_algorithms = 'INDEX_SCAN,HASH_SCAN' using this setting triggers the bug behaviour
[8 Oct 2019 17:29]
Christian Roser
We introduced the setting to avoid slaves lagging behind due to big row events on tables without primary keys. The setting reduced the lagging slaves a lot so it would be nice if we could use it without breaking replication instead
[8 Oct 2019 17:55]
MySQL Verification Team
Hi, That is a possible side effect, not my place really to tell you what to do but you really outta be finding a way to have PK on all tables. You might want to contact our MySQL Support Team to help you with that migration, I'm sure they can be of huge help. kind regards
[15 Jan 2021 0:53]
zhijun long
Version: 5.7.31 mtr case: --source include/master-slave.inc connection master; select version(); show variables like "slave_rows_search_algorithms"; connection slave; set global slave_rows_search_algorithms = 'INDEX_SCAN,HASH_SCAN'; connection master; CREATE TABLE `t1` (`id` int(11) DEFAULT NULL, `test` varchar(255) DEFAULT 'hallo', UNIQUE KEY `id` (`id`)) ENGINE=InnoDB DEFAULT CHARSET=utf8; INSERT INTO `t1` VALUES (1,'foo'),(2,'test'),(3,'lorem'); insert into t1 values(1, 'test'), (1, 'bar') on duplicate key update test=values(test); drop table t1; connection slave; show slave status; --source include/sync_slave_sql_with_master.inc set global slave_rows_search_algorithms = 'TABLE_SCAN,INDEX_SCAN'; --source include/rpl_end.inc result: Slave_IO_State Master_Host Master_User Master_Port Connect_Retry Master_Log_File Read_Master_Log_Pos Relay_Log_File Relay_Log_Pos Relay_Master_Log_File Slave_IO_Running Slave_SQL_Running Replicate_Do_DB Replicate_Ignore_DB Replicate_Do_Table Replicate_Ignore_Table Replicate_Wild_Do_Table Replicate_Wild_Ignore_Table Last_Errno Last_Error Skip_Counter Exec_Master_Log_Pos Relay_Log_Space Until_Condition Until_Log_File Until_Log_Pos Master_SSL_Allowed Master_SSL_CA_File Master_SSL_CA_Path Master_SSL_Cert Master_SSL_Cipher Master_SSL_Key Seconds_Behind_Master Master_SSL_Verify_Server_Cert Last_IO_Errno Last_IO_Error Last_SQL_Errno Last_SQL_Error Replicate_Ignore_Server_Ids Master_Server_Id Master_UUID Master_Info_File SQL_Delay SQL_Remaining_Delay Slave_SQL_Running_State Master_Retry_Count Master_Bind Last_IO_Error_Timestamp Last_SQL_Error_Timestamp Master_SSL_Crl Master_SSL_Crlpath Retrieved_Gtid_Set Executed_Gtid_Set Auto_Position Replicate_Rewrite_DB Channel_Name Master_TLS_Version Waiting for master to send event 127.0.0.1 root 13000 1 master-bin.000001 1192 slave-relay-bin.000002 933 master-bin.000001 Yes Yes 1032 Could not execute Update_rows event on table test.t1; Can't find record in 't1', Error_code: 1032; Can't find record in 't1', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 981 0 718 1614 None 0 No 0 No 0 1032 Could not execute Update_rows event on table test.t1; Can't find record in 't1', Error_code: 1032; Can't find record in 't1', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 981 1 13a3d7b7-56cd-11eb-ad0f-3c15fb5cc47b /xx/mysql-5.7.31/cmake_build/mysql-test/var/mysqld.2/data/master.info 0 NULL System lock 10 210115 04:00:36