| Bug #11401 | Load data infile 'REPLACE INTO' fails on slave. | ||
|---|---|---|---|
| Submitted: | 16 Jun 2005 22:04 | Modified: | 15 Jul 2005 7:37 |
| Reporter: | Ian Rubado | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S1 (Critical) |
| Version: | 4.1.12 | OS: | Linux (linux / solaris) |
| Assigned to: | Mats Kindahl | CPU Architecture: | Any |
[16 Jun 2005 22:04]
Ian Rubado
[16 Jun 2005 22:12]
Ian Rubado
its worth noting, this only appears to affect innodb tables. I just tested using MYISAM and the problem did not persist.
[16 Jun 2005 22:21]
Ian Rubado
changing catagory to innodb per my last comment.
[16 Jun 2005 22:27]
Ian Rubado
My problem seems identical to that in bug #5835, so I am curious if it was fixed in 4.1.7 what happened to 4.1.12?
[17 Jun 2005 8:18]
Heikki Tuuri
Jan, Ian, Jan, try to repeat this. Maybe you do not need to set up replication. Just use binlogging, and use the mysqlbinlog program to convert the binlog to SQL, and pipe in the SQL through the mysql client. Ian, please use mysqlbinlog and show what the binlog contains. It is complaining about a duplicate key error on the AUTO-INC column. This bug looks similar to one that I just fixed to 5.0.7. Regards, Heikki
[17 Jun 2005 8:34]
Heikki Tuuri
Hi! The SQL generated by mysqlbinlog is below. This SQL imports fine into 4.1.13. Looks like Jan has to set up replication to repeat the bug. Regards, Heikki /*!40019 SET @@session.max_insert_delayed_threads=0*/; # at 4 #050617 10:25:01 server id 1 log_pos 4 Start: binlog v 3, server v 4.1. 13-debug-log created 050617 10:25:01 at startup # at 79 #050617 10:27:32 server id 1 log_pos 79 Query thread_id=1 exec_tim e=0 error_code=0 use test; SET TIMESTAMP=1118993252; CREATE TABLE `testid` ( `id` int(5) unsigned NOT NULL auto_increment, `name` varchar(15) NOT NULL default '', `number` varchar(35) NOT NULL default 'default', PRIMARY KEY (`id`), UNIQUE KEY `unique_rec` (`name`,`number`) ) ENGINE=InnoDB DEFAULT CHARSET=latin1; # at 384 #050617 10:28:28 server id 1 log_pos 384 Intvar SET INSERT_ID=2; # at 412 #050617 10:28:28 server id 1 log_pos 412 Query thread_id=1 exec_tim e=0 # LOAD DATA INFILE '/home/heikki/test.txt' REPLACE INTO TABLE `testid` FIELDS T ERMINATED BY ';' OPTIONALLY ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n' STARTING BY '' (name,number); # file_id: 1 block_len: 28 # at 539 #050617 10:28:28 server id 1 log_pos 539 Intvar SET INSERT_ID=1; # at 567 #050617 10:28:28 server id 1 log_pos 567 #Exec_load: file_id=1 #050617 10:28:28 server id 1 log_pos 412 Query thread_id=1 exec_tim e=0 LOAD DATA LOCAL INFILE '/tmp/test.txt-1-2' REPLACE INTO TABLE `testid` FIELDS T ERMINATED BY ';' OPTIONALLY ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n' STARTING BY '' (name,number); # file_id: 1 block_len: 28 # at 590 #050617 10:28:32 server id 1 log_pos 590 Intvar SET INSERT_ID=4; # at 618 #050617 10:28:32 server id 1 log_pos 618 Query thread_id=1 exec_tim e=0 # LOAD DATA INFILE '/home/heikki/test.txt' REPLACE INTO TABLE `testid` FIELDS T ERMINATED BY ';' OPTIONALLY ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n' STARTING BY '' (name,number); # file_id: 2 block_len: 28 # at 745 #050617 10:28:32 server id 1 log_pos 745 Intvar SET INSERT_ID=3; # at 773 #050617 10:28:32 server id 1 log_pos 773 #Exec_load: file_id=2 #050617 10:28:32 server id 1 log_pos 618 Query thread_id=1 exec_tim e=0 LOAD DATA LOCAL INFILE '/tmp/test.txt-2-2' REPLACE INTO TABLE `testid` FIELDS T ERMINATED BY ';' OPTIONALLY ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n' STARTING BY '' (name,number);
[17 Jun 2005 8:36]
Heikki Tuuri
Ian, please double-check that you are running 4.1.12 on both the master and the slave. Regards, Heikki
[17 Jun 2005 15:04]
Ian Rubado
Heikki, I am running 4.1.12-standard on all three servers. I also believe you will need to setup a master and a slave to duplicate. If I run the load data infile command locally on the slave, the file imports fine. Its only when the slave thread tries to load it that this problem seems to come up. You mention you tested this on 4.1.13, any differences in INNODB in .13 vs .12 that may affect your outcome vs mine? Ian
[17 Jun 2005 15:06]
Heikki Tuuri
Ian, I did not yet test in a replication setup. I just tested that the SQL in binlog works ok in a single server. I think there are no changes 4.1.12 -> 4.1.13. Regards, Heikki
[17 Jun 2005 15:06]
Heikki Tuuri
Ian, I did not yet test in a replication setup. I just tested that the SQL in binlog works ok in a single server. I think there are no changes 4.1.12 -> 4.1.13. Regards, Heikki
[17 Jun 2005 15:10]
Ian Rubado
Heikki, I see, thanks. Hopefully, Jan can confirm the issue soon; so I can find some resoltuion. Ian
[22 Jun 2005 5:56]
Jan Lindström
Thank you for your bug report. However, I can't repeat your problem with 4.1.13bk. After starting master and one slave both using innobase_file_per_table option I cave following command to master:
jan@hundin:~/mysql-4.1/client> ./mysql -u root
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 4 to server version: 4.1.13-debug-log
Type 'help;' or '\h' for help. Type '\c' to clear the buffer.
mysql> create database test;
Query OK, 1 row affected (0.02 sec)
mysql> use test;
Database changed
mysql> CREATE TABLE `testid` (
-> `id` int(5) unsigned NOT NULL auto_increment,
-> `name` varchar(15) NOT NULL default '',
-> `number` varchar(35) NOT NULL default 'default',
-> PRIMARY KEY (`id`),
-> UNIQUE KEY `unique_rec` (`name`,`number`)
-> ) ENGINE=InnoDB DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.14 sec)
mysql> commit;
Query OK, 0 rows affected (0.00 sec)
mysql> LOAD DATA LOCAL INFILE '/home/jan/load.txt' REPLACE INTO TABLE `testid` FIELDS TERMINATED BY ';' OPTIONALLY ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n' STARTING BY '' (name,number);
Query OK, 2 rows affected (0.04 sec)
Records: 2 Deleted: 0 Skipped: 0 Warnings: 0
mysql> select * from testid;
+----+------+--------+
| id | name | number |
+----+------+--------+
| 1 | XXX | 12345 |
| 2 | XXY | 12345 |
+----+------+--------+
2 rows in set (0.02 sec)
And this is what I found from slave:
jan@hundin:~/apu> ../mysql-4.1/client/mysql --port=5121 -u root
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 3 to server version: 4.1.13-debug-log
Type 'help;' or '\h' for help. Type '\c' to clear the buffer.
mysql> use test;
Database changed
mysql> select * from testid;
+----+------+--------+
| id | name | number |
+----+------+--------+
| 1 | XXX | 12345 |
| 2 | XXY | 12345 |
+----+------+--------+
2 rows in set (0.00 sec)
No errors on both server logs and binlogs seem to be correct, i.e. slave binlog shows:
jan@hundin:~/sqldata2> more hundin-relay-bin.000001
bin ( binlog.000001B K 4.1.13-debug-logBB DO grant all on *.* to 'jan'@'lo
calhost'B 7 testcreate database testB 1 testCREATE TABLE `testid` (
`id` int(5) unsigned NOT NULL auto_increment,
`name` varchar(15) NOT NULL default '',
`number` varchar(35) NOT NULL default 'default',
PRIMARY KEY (`id`),
UNIQUE KEY `unique_rec` (`name`,`number`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1rB r| ; "
\ namenumbertestidtest/home/jan/load.txt"XXX";"12345"
"XXY";"12345"
rB rB
Regards,
JanL
[22 Jun 2005 6:15]
Jan Lindström
One more note. I can execute the given load command several times without any errors on both server logs and results are correct:
Master:
mysql> LOAD DATA LOCAL INFILE '/home/jan/load.txt' REPLACE INTO TABLE `testid` FIELDS TERMINATED BY ';' OPTIONALLY ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n' STARTING BY '' (name,number);
Query OK, 4 rows affected (0.01 sec)
Records: 2 Deleted: 2 Skipped: 0 Warnings: 0
mysql> select * from testid;
+----+------+--------+
| id | name | number |
+----+------+--------+
| 3 | XXX | 12345 |
| 4 | XXY | 12345 |
+----+------+--------+
2 rows in set (0.00 sec)
Slave:
mysql> select * from testid;
+----+------+--------+
| id | name | number |
+----+------+--------+
| 3 | XXX | 12345 |
| 4 | XXY | 12345 |
+----+------+--------+
2 rows in set (0.00 sec)
Regards,
JanL
[22 Jun 2005 6:17]
Ian Rubado
Jan, Please re-read my original bug submission. 1st Load file works fine, its the second and consecutive that will fail on the slave. If you try the load file on the master more than once, you will be able to duplicate. It seems the problem is when the second load file needs to delete and insert records since there are matches to the unique key. It only occurs when data is actually being 'replaced'. Ian
[22 Jun 2005 6:18]
Ian Rubado
Could it be 4.1.12 vs 4.1.13? Ian
[22 Jun 2005 6:42]
Jan Lindström
Only change to the replication found from 4.1.13 changelog in the manual is: Queries of the form UPDATE ... (SELECT ... ) SET ... run on a replication master would crash all the slaves. (Bug#10442) These problems are not at least directly connected. I'm not aware other changes to the replication between 4.1.12 and 4.1.13. Regards, JanL
[22 Jun 2005 7:04]
Jan Lindström
I tested with 4.1.12-standard-log using my laptop and one master and one slave and still can't repeat your problem.
Master:
jplindst@t41:~$ mysql --port=3408 -u root
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 4 to server version: 4.1.12-standard-log
Type 'help;' or '\h' for help. Type '\c' to clear the buffer.
mysql> create database test;
Query OK, 1 row affected (0.33 sec)
mysql> use test;
Database changed
mysql> CREATE TABLE `testid` ( `id` int(5) unsigned NOT NULL auto_increment, `name` varchar(15) NOT NULL default '', `number` varchar(35) NOT NULL default 'default', PRIMARY KEY (`id`), UNIQUE KEY `unique_rec` (`name`,`number`) ) ENGINE=InnoDB DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.49 sec)
mysql> LOAD DATA LOCAL INFILE '/home/jplindst/load.txt' REPLACE INTO TABLE `testid` FIELDS TERMINATED BY ';' OPTIONALLY ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n' STARTING BY '' (name,number); Query OK, 2 rows affected (0.40 sec)
Records: 2 Deleted: 0 Skipped: 0 Warnings: 0
mysql> LOAD DATA LOCAL INFILE '/home/jplindst/load.txt' REPLACE INTO TABLE `testid` FIELDS TERMINATED BY ';' OPTIONALLY ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n' STARTING BY '' (name,number);
Query OK, 4 rows affected (0.28 sec)
Records: 2 Deleted: 2 Skipped: 0 Warnings: 0
mysql> select * from testid;
+----+------+--------+
| id | name | number |
+----+------+--------+
| 3 | XXX | 12345 |
| 4 | XXY | 12345 |
+----+------+--------+
2 rows in set (0.28 sec)
Slave:
jplindst@t41:~$ mysql --port=3306 -u root
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 5 to server version: 4.1.12-standard-log
Type 'help;' or '\h' for help. Type '\c' to clear the buffer.
mysql> use test;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A
Database changed
mysql> select * from testid;
+----+------+--------+
| id | name | number |
+----+------+--------+
| 3 | XXX | 12345 |
| 4 | XXY | 12345 |
+----+------+--------+
2 rows in set (0.00 sec)
Slave binlog:
jplindst@t41:~/sqldata2$ more binlog.000001
bin
B K 4.1.12-standard-log
B@^LB 7 testcreate database testG^LB 1 testCREATE TABLE `tes
tid` ( `id` int(5) unsigned NOT NULL auto_increment, `name` varchar(15) NOT
NULL default '', `number` varchar(35) NOT NULL default 'default', PRIMARY KEY (`id`), UNIQUE KEY `unique_rec` (`name`,`number`) ) ENGINE=InnoDB DEFAULT CHARSET=latin1c^LB c^L ; "
\ namenumbertestidtest/home/jplindst/load.txt"XXX";"12345"
"XXY";"12345"
c^LB T c^LB
p e^LB e^L ; "
\ namenumbertestidtest/home/jplindst/load.txt"XXX";"12345"
"XXY";"12345"
e^LB $ e^LB
@
[22 Jun 2005 22:41]
Ian Rubado
Jan, Sorry for the deluge of comments, but I have noticed one other thing. Your calls to mysql are like this: mysql --port=3306 -u root and mysql -u root when testing 4.1.13. Perhaps its just me, but when I try the same connection method I keep connecting to the same server running on 'localhost'. The only way I was able to connect to my slave was to use -S <slave socket file>. This may or may not be the case for you, but could you verify that you are indeed connecting to the slave when you check it? Perhaps by checking the server_id var which should be different for both master and slave. You may be using different options than me which may explain the differences, but mysqls default is to use the socket when connecting to localhost is it not? You would need to use -h <hostname> and -p <port> for it to use tcp, wouldnt you? regards, Ian
[23 Jun 2005 5:30]
Jan Lindström
Ian, Thank you for your help. You are correct, I'm not sure which server I really was connected maybe to slave in the both connections. But now I could repeat your problem with 4.1.12. jplindst@t41:~$ 050623 8:21:29 [ERROR] Slave: Error 'Duplicate entry '3' for key 1' running LOAD DATA INFILE on table 'testid'. Default database: 'test', Error_code: 1062 050623 8:21:29 [ERROR] Slave: Error 'Duplicate entry '3' for key 1' running LOAD DATA INFILE on table 'testid'. Default database: 'test'. Failed executing load from '/tmp/SQL_LOAD-128-512-2.info', Error_code: 1062 050623 8:21:29 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'binlog.000001' position 804 jplindst@t41:/tmp$ more SQL_LOAD-128-512-2.info FB^L e ; " \ namenumbertestidtest/tmp/SQL_LOAD-128-512-2.data jplindst@t41:/tmp$ more SQL_LOAD-128-512-2.data "XXX";"12345" "XXY";"12345" jplindst@t41:~/sqldata2$ more t41-relay-bin.000001 bin ( binlog.000001)FB K 4.1.12-standard-log)FBFB 7 testcreate database testFB 1 testCRE ATE TABLE `testid` ( `id` int(5) unsigned NOT NULL auto_increment, `name` varchar(15) NOT NULL default '', `number` varchar(35) NOT NULL default 'default', PRIMARY KEY (`id`), UNIQUE KEY `unique_rec` (`name`,`number`) ) ENGINE=InnoDB DEFAULT CHARSET=latin1FB F ; " \ namenumbertestidtest/home/jplindst/load.txt"XXX";"12345" "XXY";"12345" FB T FB p FB F ; " \ namenumbertestidtest/home/jplindst/load.txt"XXX";"12345" "XXY";"12345" FB $ FB @ jplindst@t41:~$ mysql -S /home/jplindst/bugsocket2 Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 3 to server version: 4.1.12-standard-log Type 'help;' or '\h' for help. Type '\c' to clear the buffer. mysql> show variables; +---------------------------------+------------------------------------------+ | Variable_name | Value | +---------------------------------+------------------------------------------+ | back_log | 50 | | basedir | /home/jplindst/ | | binlog_cache_size | 32768 | | bulk_insert_buffer_size | 8388608 | | character_set_client | latin1 | | character_set_connection | latin1 | | character_set_database | latin1 | | character_set_results | latin1 | | character_set_server | latin1 | | character_set_system | utf8 | | character_sets_dir | /usr/share/mysql/charsets/ | | collation_connection | latin1_swedish_ci | | collation_database | latin1_swedish_ci | | collation_server | latin1_swedish_ci | | concurrent_insert | ON | | connect_timeout | 5 | | datadir | /home/jplindst/sqldata2/ | | date_format | %Y-%m-%d | | datetime_format | %Y-%m-%d %H:%i:%s | | default_week_format | 0 | | delay_key_write | ON | | delayed_insert_limit | 100 | | delayed_insert_timeout | 300 | | delayed_queue_size | 1000 | | expire_logs_days | 0 | | flush | OFF | | flush_time | 0 | | ft_boolean_syntax | + -><()~*:""&| | | ft_max_word_len | 84 | | ft_min_word_len | 4 | | ft_query_expansion_limit | 20 | | ft_stopword_file | (built-in) | | group_concat_max_len | 1024 | | have_archive | NO | | have_bdb | NO | | have_blackhole_engine | NO | | have_compress | YES | | have_crypt | YES | | have_csv | NO | | have_example_engine | NO | | have_geometry | YES | | have_innodb | YES | | have_isam | NO | | have_ndbcluster | NO | | have_openssl | NO | | have_query_cache | YES | | have_raid | NO | | have_rtree_keys | YES | | have_symlink | YES | | init_connect | | | init_file | | | init_slave | | | innodb_additional_mem_pool_size | 10485760 | | innodb_autoextend_increment | 8 | | innodb_buffer_pool_awe_mem_mb | 0 | | innodb_buffer_pool_size | 104857600 | | innodb_data_file_path | ibdata1:20M:autoextend | | innodb_data_home_dir | /home/jplindst/sqldata2 | | innodb_fast_shutdown | ON | | innodb_file_io_threads | 4 | | innodb_file_per_table | ON | | innodb_flush_log_at_trx_commit | 1 | | innodb_flush_method | | | innodb_force_recovery | 0 | | innodb_lock_wait_timeout | 50 | | innodb_locks_unsafe_for_binlog | OFF | | innodb_log_arch_dir | /home/jplindst/sqldata2 | | innodb_log_archive | OFF | | innodb_log_buffer_size | 1048576 | | innodb_log_file_size | 26214400 | | innodb_log_files_in_group | 2 | | innodb_log_group_home_dir | /home/jplindst/sqldata2 | | innodb_max_dirty_pages_pct | 90 | | innodb_max_purge_lag | 0 | | innodb_mirrored_log_groups | 1 | | innodb_open_files | 300 | | innodb_table_locks | ON | | innodb_thread_concurrency | 8 | | interactive_timeout | 28800 | | join_buffer_size | 131072 | | key_buffer_size | 8388600 | | key_cache_age_threshold | 300 | | key_cache_block_size | 1024 | | key_cache_division_limit | 100 | | language | /usr/share/mysql/english/ | | large_files_support | ON | | license | GPL | | local_infile | ON | | locked_in_memory | OFF | | log | OFF | | log_bin | ON | | log_error | | | log_slave_updates | OFF | | log_slow_queries | OFF | | log_update | OFF | | log_warnings | 1 | | long_query_time | 10 | | low_priority_updates | OFF | | lower_case_file_system | OFF | | lower_case_table_names | 0 | | max_allowed_packet | 1048576 | | max_binlog_cache_size | 4294967295 | | max_binlog_size | 10485760 | | max_connect_errors | 10 | | max_connections | 100 | | max_delayed_threads | 20 | | max_error_count | 64 | | max_heap_table_size | 16777216 | | max_insert_delayed_threads | 20 | | max_join_size | 4294967295 | | max_length_for_sort_data | 1024 | | max_relay_log_size | 0 | | max_seeks_for_key | 4294967295 | | max_sort_length | 1024 | | max_tmp_tables | 32 | | max_user_connections | 0 | | max_write_lock_count | 4294967295 | | myisam_data_pointer_size | 4 | | myisam_max_extra_sort_file_size | 2147483648 | | myisam_max_sort_file_size | 2147483647 | | myisam_recover_options | OFF | | myisam_repair_threads | 1 | | myisam_sort_buffer_size | 8388608 | | net_buffer_length | 16384 | | net_read_timeout | 30 | | net_retry_count | 10 | | net_write_timeout | 60 | | new | OFF | | old_passwords | OFF | | open_files_limit | 1024 | | pid_file | /home/jplindst/sqldata2/t41.pid | | port | 5122 | | preload_buffer_size | 32768 | | protocol_version | 10 | | query_alloc_block_size | 8192 | | query_cache_limit | 1048576 | | query_cache_min_res_unit | 4096 | | query_cache_size | 0 | | query_cache_type | ON | | query_cache_wlock_invalidate | OFF | | query_prealloc_size | 8192 | | range_alloc_block_size | 2048 | | read_buffer_size | 131072 | | read_only | OFF | | read_rnd_buffer_size | 262144 | | relay_log_purge | ON | | relay_log_space_limit | 0 | | rpl_recovery_rank | 0 | | secure_auth | OFF | | server_id | 128 | | skip_external_locking | ON | | skip_networking | OFF | | skip_show_database | OFF | | slave_net_timeout | 3600 | | slave_transaction_retries | 0 | | slow_launch_time | 2 | | socket | /home/jplindst/bugsocket2 | | sort_buffer_size | 2097144 | | sql_mode | | | storage_engine | InnoDB | | sql_notes | OFF | | sql_warnings | OFF | | sync_binlog | 0 | | sync_replication | 0 | | sync_replication_slave_id | 0 | | sync_replication_timeout | 0 | | sync_frm | ON | | system_time_zone | EEST | | table_cache | 64 | | table_type | InnoDB | | thread_cache_size | 0 | | thread_stack | 126976 | | time_format | %H:%i:%s | | time_zone | SYSTEM | | tmp_table_size | 33554432 | | tmpdir | | | transaction_alloc_block_size | 8192 | | transaction_prealloc_size | 4096 | | tx_isolation | REPEATABLE-READ | | version | 4.1.12-standard-log | | version_comment | MySQL Community Edition - Standard (GPL) | | version_compile_machine | i686 | | version_compile_os | pc-linux-gnu | | wait_timeout | 28800 | +---------------------------------+------------------------------------------+ 184 rows in set (0.00 sec) mysql> show slave status; +----------------------------------+-------------+-------------+-------------+---------------+-----------------+---------------------+----------------------+---------------+-----------------------+------------------+-------------------+-----------------+---------------------+--------------------+------------------------+-------------------------+-----------------------------+------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------+---------------------+-----------------+-----------------+----------------+---------------+--------------------+--------------------+--------------------+-----------------+-------------------+----------------+-----------------------+ | 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 | +----------------------------------+-------------+-------------+-------------+---------------+-----------------+---------------------+----------------------+---------------+-----------------------+------------------+-------------------+-----------------+---------------------+--------------------+------------------------+-------------------------+-----------------------------+------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------+---------------------+-----------------+-----------------+----------------+---------------+--------------------+--------------------+--------------------+-----------------+-------------------+----------------+-----------------------+ | Waiting for master to send event | localhost | root | 5120 | 60 | binlog.000001 | 855 | t41-relay-bin.000001 | 844 | binlog.000001 | Yes | No | | | | | | | 1062 | Error 'Duplicate entry '3' for key 1' running LOAD DATA INFILE on table 'testid'. Default database: 'test'. Failed executing load from '/tmp/SQL_LOAD-128-512-2.info' | 0 | 804 | 895 | None | | 0 | No | | | | | | NULL | +----------------------------------+-------------+-------------+-------------+---------------+-----------------+---------------------+----------------------+---------------+-----------------------+------------------+-------------------+-----------------+---------------------+--------------------+------------------------+-------------------------+-----------------------------+------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------+---------------------+-----------------+-----------------+----------------+---------------+--------------------+--------------------+--------------------+-----------------+-------------------+----------------+-----------------------+ 1 row in set (0.60 sec)
[23 Jun 2005 5:58]
Heikki Tuuri
Jan,
I added debug printfs to check this in the slave. The reason for the bug is that in the slave, the 'if' below does not recognize it as a REPLACE type command.
Run the slave process inside gdb, and find out what are:
user_thd->lex->sql_command == SQLCOM_LOAD
user_thd->lex->duplicates == DUP_REPLACE
Regards,
Heikki
ha_innodb.cc:
printf("Is this a REPLACE?\n");
if (error == DB_DUPLICATE_KEY
&& (user_thd->lex->sql_command == SQLCOM_REPLACE
|| user_thd->lex->sql_command
== SQLCOM_REPLACE_SELECT
|| (user_thd->lex->sql_command == SQLCOM_LOAD
&& user_thd->lex->duplicates == DUP_REPLACE))) {
skip_auto_inc_decr= TRUE;
printf("YES!\n");
}
[23 Jun 2005 6:26]
Jan Lindström
This is what I get with 4.1.13bk and gdb:
Breakpoint 1, ha_innobase::write_row(char*) (this=0x8b351c0,
record=0x8b352c8 "\003") at ha_innodb.cc:2571
2571 if (error == DB_DUPLICATE_KEY
(gdb) p error
$1 = 17
(gdb) list
2566 longer have the AUTO-INC lock, and cannot decrement
2567 the counter here. */
2568
2569 skip_auto_inc_decr = FALSE;
2570
2571 if (error == DB_DUPLICATE_KEY
2572 && (user_thd->lex->sql_command == SQLCOM_REPLACE
2573 || user_thd->lex->sql_command
2574 == SQLCOM_REPLACE_SELECT
2575 || (user_thd->lex->sql_command == SQLCOM_LOAD
(gdb) p user_thd->lex->sql_command
$2 = SQLCOM_END
(gdb) list
2576 && user_thd->lex->duplicates == DUP_REPLACE))) {
2577
2578 skip_auto_inc_decr= TRUE;
2579 }
2580
2581 if (!skip_auto_inc_decr && incremented_auto_inc_counter
2582 && prebuilt->trx->auto_inc_lock) {
2583 dict_table_autoinc_decrement(prebuilt->table);
2584 }
2585
(gdb) p user_thd->lex->duplicates
$3 = DUP_ERROR
(gdb) c
Continuing.
Breakpoint 1, ha_innobase::write_row(char*) (this=0x8b351c0,
record=0x8b352c8 "\003") at ha_innodb.cc:2571
2571 if (error == DB_DUPLICATE_KEY
(gdb) p error
$4 = 17
(gdb) p user_thd->lex->sql_command
$5 = SQLCOM_END
(gdb) p user_thd->lex->duplicates
$6 = DUP_ERROR
(gdb) c
Continuing.
050623 8:28:02 [ERROR] Slave: Error 'Duplicate entry '3' for key 1' running LOAD DATA INFILE on table 'testid'. Default database: 'test', Error_code: 1062
050623 8:28:02 [ERROR] Slave: Error 'Duplicate entry '3' for key 1' running LOAD DATA INFILE on table 'testid'. Default database: 'test'. Failed executing load from '/tmp/SQL_LOAD-128-245-2.info', Error_code: 1062
050623 8:28:02 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'binlog.000001' position 794
[23 Jun 2005 8:51]
Heikki Tuuri
Hi! Re-assigning this to Guilhem. Looks like slave.cc processes LOAD DATA INFILE in a special way, past the SQL interpreter. That is why lex is not properly initialized. Fix: the slave code should set the lex struct in a sensible way . Regards, Heikki
[23 Jun 2005 9:19]
Guilhem Bichot
Hi Heikki, In my humble opinion, a storage engine should not rely on user_thd->lex->sql_command. The SQL layer calls ha_innodb::extra(HA_EXTRA_IGNORE_DUP_KEY), and I guess ha_innodb::extra() should do something with this value instead of ignoring it. That's how ha_berkeley.cc does. The storage engine is not supposed to know what SQL command is the caller, it's just supposed to write a row with possible optional overwriting if the caller tells it to (through HA_EXTRA_IGNORE_DUP_KEY). Of course as a quickfix, we can set user_thd->lex->sql_command to SQLCOM_LOAD in replication. But this problem is already fixed in 5.0 where replication of LOAD DATA INFILE has been changed (and where SQLCOM_LOAD is set). I'm un-assigning it from me; Brian may assign it later on.
[23 Jun 2005 12:22]
Heikki Tuuri
Guilhem,
storage engines do use the information in thd->lex->sql_command. For example, locking depends on that value. Also assignment of auto-inc values may depend on the value.
Ideally, the SQL interpreter should do everything, and table handlers would not need to know the SQL command. But in practice it has not been built that way.
Replication should therefore replay the SQL so that:
thd->lex->sql_command
and
thd->lex->duplicates == DUP_REPLACE
are sensible.
Regards,
Heikki
From ha_innodb.cc:
if (srv_locks_unsafe_for_binlog &&
prebuilt->trx->isolation_level != TRX_ISO_SERIALIZABLE &&
(lock_type == TL_READ || lock_type == TL_READ_NO_INSERT) &&
thd->lex->sql_command != SQLCOM_SELECT &&
thd->lex->sql_command != SQLCOM_UPDATE_MULTI &&
thd->lex->sql_command != SQLCOM_DELETE_MULTI &&
thd->lex->sql_command != SQLCOM_LOCK_TABLES) {
[23 Jun 2005 19:25]
Guilhem Bichot
Hello Heikki, Well in this particular case the SQL interpreter does everything, i.e. it tells the storage engine that it should replace instead of returning duplicate error; this is done through ha_innodb::extra(HA_EXTRA_IGNORE_DUP_KEY); if InnoDB didn't ignore this call it would know. But nevermind, setting thd->lex->sql_command in the slave SQL thread is easy and we'll do it in 4.1 (and in 5.0 the bug should not exist at all). Thanks much to Ian, Jan and you for the deep analysis which will save the replication team hours :)
[23 Jun 2005 22:24]
Ian Rubado
Hi, Jan's verification of the bug has certainly uplifted my spirits. At least I know I am sane! When do you expect a fix added to the 4.1.13bk source? Thanks to all the developers for working on a truly great piece of software. Regards, Ian
[5 Jul 2005 13:56]
Mats Kindahl
Thank you for your bug report. This issue has been committed to our
source repository of that product and will be incorporated into the
next release.
If necessary, you can access the source repository and build the latest
available version, including the bugfix, yourself. More information
about accessing the source trees is available at
http://www.mysql.com/doc/en/Installing_source_tree.html
[8 Jul 2005 18:42]
Jon Stephens
Thank you for your bug report. This issue has been committed to our
source repository of that product and will be incorporated into the
next release.
If necessary, you can access the source repository and build the latest
available version, including the bugfix, yourself. More information
about accessing the source trees is available at
http://www.mysql.com/doc/en/Installing_source_tree.html
Additional info:
Fix documented for 4.1.13; closed bug report.
[15 Jul 2005 7:37]
Heikki Tuuri
Guilhem, heikki@hundin:~/mysql-4.1/include> grep -n HA_EXTRA_IGNORE_DUP_KEY *.h my_base.h:131: HA_EXTRA_IGNORE_DUP_KEY, /* Dup keys don't rollba ck everything*/ I do not see how that ::extra() directive is related to auto-increment handling or REPLACE. Actually, I do not understand what it specifies. The SQL interpreter decides on a higher level whether to roll back the whole SQL statement if there is a duplicate key error from the handler. Regards, Heikki
