| Bug #69185 | Replication breaks during concurrent INSERTs and LOAD DATA in a auto_inc table | ||
|---|---|---|---|
| Submitted: | 9 May 2013 15:23 | Modified: | 24 Feb 2014 12:33 |
| Reporter: | Ovais Tariq | Email Updates: | |
| Status: | Verified | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S2 (Serious) |
| Version: | 5.1.69 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
[9 May 2013 15:27]
Ovais Tariq
Test script to execute INSERT and LOAD DATA concurrently
Attachment: test_insert.sh (application/octet-stream, text), 913 bytes.
[9 May 2013 15:28]
Ovais Tariq
MySQL binlog that caused replication failure
Attachment: mysql-bin.000014 (application/octet-stream, text), 2.14 KiB.
[9 May 2013 15:31]
Ovais Tariq
file used in the LOAD DATA INFILE
Attachment: SQL_LOAD_MB-17a99f5-3 (application/octet-stream, text), 20 bytes.
[9 May 2013 18:53]
MySQL Verification Team
Hello Ovais, Thank you for the report. Verified as described. Thanks, Umesh
[9 May 2013 19:01]
MySQL Verification Team
- Had to run load file some 18+ times to hit this error
## Duplicate error on slave
slave1 [localhost] {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: 29984
Connect_Retry: 60
Master_Log_File: mysql-bin.000024
Read_Master_Log_Pos: 2163
Relay_Log_File: mysql_sandbox29985-relay-bin.000038
Relay_Log_Pos: 1177
Relay_Master_Log_File: mysql-bin.000019
Slave_IO_Running: Yes
Slave_SQL_Running: No
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 1062
Last_Error: Error 'Duplicate entry '1' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO tbl_auto_col_only_on_slave SET col1 = 23211, col2 = 'foo', col3 = 'bar', col4 = 1, col5 = 242122'
Skip_Counter: 0
Exec_Master_Log_Pos: 1032
Relay_Log_Space: 16394
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: NULL
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 1062
Last_SQL_Error: Error 'Duplicate entry '1' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO tbl_auto_col_only_on_slave SET col1 = 23211, col2 = 'foo', col3 = 'bar', col4 = 1, col5 = 242122'
1 row in set (0.00 sec)
[9 May 2013 19:02]
MySQL Verification Team
Test case...
Attachment: 69185.txt (text/plain), 2.71 KiB.
[9 Jan 2014 22:55]
Roel Van de Paar
Ovais, Umesh, Is InnoDB also affected? Is 5.5/5.6 also affected?
[24 Feb 2014 12:16]
Ovais Tariq
Hello Roel, I haven't been able to reproduce it on 5.5 or 5.6
[24 Feb 2014 12:33]
Ovais Tariq
I have also not been able to reproduce it on 5.1 with InnoDB. So this appears to be a MyISAM only bug.
Description: Under certain conditions concurrent execution of INSERTs and LOAD DATA in an auto_increment table will cause replication to break on the slave with a duplicate key error. For this condition to be met the table involved in the INSERTs will not have an auto_incrementing column on the master but will have a auto_incrementing column on the slave. This is caused by the INSERT being logged within the LOAD DATA INFILE block of events. Following is what the binary log contents look like in this case: # at 961 #130509 17:15:59 server id 1 end_log_pos 989 Intvar SET INSERT_ID=1/*!*/; # at 989 #130509 17:15:59 server id 1 end_log_pos 1032 #Begin_load_query: file_id: 12 block_len: 20 # at 1032 #130509 17:15:59 server id 1 end_log_pos 1203 Query thread_id=182 exec_time=0 error_code=0 SET TIMESTAMP=1368112559/*!*/; INSERT INTO tbl_auto_col_only_on_slave SET col1 = 23211, col2 = 'foo', col3 = 'bar', col4 = 1, col5 = 242122 /*!*/; # at 1203 #130509 17:15:59 server id 1 end_log_pos 1231 Intvar SET INSERT_ID=1/*!*/; # at 1231 #130509 17:15:59 server id 1 end_log_pos 1512 Execute_load_query thread_id=181 exec_time=0 error_code=0 SET TIMESTAMP=1368112559/*!*/; LOAD DATA LOCAL INFILE '/tmp/SQL_LOAD_MB-c-0' INTO TABLE `tbl_auto_col` FIELDS TERMINATED BY ',' ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n' (`c`) /*!*/; # file_id: 12 As you can see that there is an INSERT logged in the binary log within the group of events belonging to the LOAD DATA, which means the INSERT on the slave will use the auto_increment value of 1 because of "SET INSERT_ID=1" being present before the INSERT. And the slave fails as follows: slave1 [localhost] {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: 29984 Connect_Retry: 60 Master_Log_File: mysql-bin.000014 Read_Master_Log_Pos: 2196 Relay_Log_File: mysql_sandbox29985-relay-bin.000026 Relay_Log_Pos: 1177 Relay_Master_Log_File: mysql-bin.000014 Slave_IO_Running: Yes Slave_SQL_Running: No Replicate_Do_DB: Replicate_Ignore_DB: Replicate_Do_Table: Replicate_Ignore_Table: Replicate_Wild_Do_Table: Replicate_Wild_Ignore_Table: Last_Errno: 1062 Last_Error: Error 'Duplicate entry '1' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO tbl_auto_col_only_on_slave SET col1 = 23211, col2 = 'foo', col3 = 'bar', col4 = 1, col5 = 242122' Skip_Counter: 0 Exec_Master_Log_Pos: 1032 Relay_Log_Space: 2552 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: NULL Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 1062 Last_SQL_Error: Error 'Duplicate entry '1' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO tbl_auto_col_only_on_slave SET col1 = 23211, col2 = 'foo', col3 = 'bar', col4 = 1, col5 = 242122' 1 row in set (0.00 sec) How to repeat: Create the following MyISAM tables: CREATE TABLE `tbl_auto_col` ( `id` int(11) NOT NULL auto_increment, `c` char(3) default NULL, PRIMARY KEY (`id`) ) ENGINE=MyISAM DEFAULT CHARSET=latin1; CREATE TABLE `tbl_auto_col_only_on_slave` ( `col1` int(11) DEFAULT NULL, `col2` varchar(100) DEFAULT NULL, `col3` varchar(100) DEFAULT NULL, `col4` int(11) DEFAULT NULL, `col5` int(11) DEFAULT NULL ) ENGINE=MyISAM DEFAULT CHARSET=latin1; Alter the table tbl_auto_col_only_on_slave on the slave to add an auto_increment column: -- on slave: alter table tbl_auto_col_only_on_slave add column id bigint(20) NOT NULL AUTO_INCREMENT PRIMARY KEY; Create a file to be loaded by LOAD DATA INFILE: [root@ovaistariq-test master]# cat /tmp/SQL_LOAD_MB-17a99f5-3 17d c44 019 69b 9c5 Run the script attached to this bug report: ./test_insert.sh The script would need to be executed multiple times before the condition can be produced, I was able to produce the bug by executing the script test_insert.sh 7 times.