MySQL Bugs: #42311: load data infile replication 4.1 to 6.0 fails

Bug #42311	load data infile replication 4.1 to 6.0 fails
Submitted:	23 Jan 2009 19:17	Modified:	23 Sep 2009 9:31
Reporter:	Andrei Elkin	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	6.0, 5.1	OS:	Any
Assigned to:	Assigned Account	CPU Architecture:	Any
Tags:	disabled, mdl

Description:
Merging fixes for Bug #31240 to 6.0 tree ended up with a fired assert:
#0  0x085188f0 in mdl_add_lock (context=0x980a33c, lock_data=0x0) at mdl.cc:342
#1  0x08356ccf in open_table_get_mdl_lock (thd=0x980a2c8, table_list=0xaf8b7700, mdl_lock_data=0x0, flags=0, action=0xaf8b7028) at sql_base.cc:2272
#2  0x0835b7a5 in open_table (thd=0x980a2c8, table_list=0xaf8b7700, mem_root=0xaf8b6fdc, action=0xaf8b7028, flags=0) at sql_base.cc:2564
#3  0x0835ccd0 in open_tables (thd=0x980a2c8, start=0xaf8b7094, counter=0xaf8b7080, flags=0) at sql_base.cc:3737
#4  0x0835d3af in open_and_lock_tables_derived (thd=0x980a2c8, tables=0xaf8b7700, derived=true, flags=0) at sql_base.cc:4186
#5  0x0830fc78 in open_and_lock_tables (thd=0x980a2c8, tables=0xaf8b7700) at ../../sql/mysql_priv.h:1574
#6  0x08477873 in mysql_load (thd=0x980a2c8, ex=0xaf8b7638, table_list=0xaf8b7700, fields_vars=@0xaf8b76d0, set_fields=@0xaf8b76c4, set_values=@0xaf8b76c4, handle_duplicates=DUP_ERROR, ignore=false, read_file_from_client=false) at sql_load.cc:183
#7  0x08407848 in Load_log_event::do_apply_event (this=0x98213c8, net=0x0, rli=0x97a2578, use_rli_only_for_errors=true) at log_event.cc:4533
#8  0x0840e284 in Execute_load_log_event::do_apply_event (this=0x98145b0, rli=0x97a2578) at log_event.cc:6423
#9  0x084b4a21 in Log_event::apply_event (this=0x98145b0, rli=0x97a2578) at log_event.h:1055
#10 0x084acbbd in apply_event_and_update_pos (ev=0x98145b0, thd=0x980a2c8, rli=0x97a2578, skip=true) at slave.cc:1842
#11 0x084ae10b in exec_relay_log_event (thd=0x980a2c8, rli=0x97a2578) at slave.cc:1985
#12 0x084aef35 in handle_slave_sql (arg=0x97a1278) at slave.cc:2665

This designates a separate to the mentioned bug problem of handling LOAD DATA INFILE replication from 4.1 to 6.0.

rpl_cross_version test is set to disabled till the current bug is solved.

How to repeat:
mtr rpl_cross_version

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/63935

2974 Andrei Elkin	2009-01-23 [merge]
      Bug #42311 load data infile replication 4.1 to 6.0 fails
      
      merging from 5.1-bt and disabling rpl_cross_version due to the aforementioned bug.

Verified as described. Thank you for the bug report.

This is not a new issue, and this is not a bug.

As stated in the Manual (http://dev.mysql.com/doc/refman/5.1/en/replication-compatibility.html - 5.1 version cited here but the other versions say the same thing),

MySQL supports replication from one major version to the next higher
major version. For example, you can replicate from a master running
MySQL 4.1 to a slave running MySQL 5.0, from a master running MySQL 5.0
to a slave running MySQL 5.1, and so on.

In some cases, it is also possible to replicate between a master and a
slave that is more than one major version newer than the master.
However, there are known issues with trying to replicate from a master
running MySQL 4.1 or earlier to a slave running MySQL 5.1 or later...
In such cases, you can insert a MySQL server running an intermediate
version between the two; for example, rather than replicating directly
from a MySQL 4.1 master to a MySQL 5.1 slave, it is possible to
replicate from a MySQL 4.1 server to a MySQL 5.0 server, and then from
the MySQL 5.0 server to a MySQL 5.1 server.

Translation: "Replication between one major series and the next is supported. Replication between servers more than one major series apart *might* work, but there are no guarantees".

So users should *already* not have any expectation that 4.1->6.0
replication will "just work"; instead, they should be prepared to use intermediaries, (as has been suggested here).

Set status to !BUG for reasons stated.

Pushed into 6.0.10-alpha (revid:kostja@sun.com-20090204104420-mw1i2u9lum4bxjo6) (version source revid:aelkin@mysql.com-20090123192116-kg0rza3xkvq3nc94) (merge vers: 6.0.10-alpha) (pib:6)

I agree with the docs we may not always support a version leap
replication, but we should not crash either.

cheers,

Andrei

As per my discussion with Andrei on IRC a few moments ago:

I somehow managed to miss the word "crash". :(

I withdraw my previous objections.

rpl_cross_version started failing on MacOSX in 5.1 as well.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/70674

2848 Georgi Kodinov	2009-03-27
      disabled a failing test suite due to bug #42311

failing output in 5.1-pe-stage:
rpl.rpl_cross_version                    [ fail ]
        Test ended at 2009-03-27 06:17:06

CURRENT_TEST: rpl.rpl_cross_version
--- /Users/henry/pb/bzr_mysql-5.1-pe-stage/14/mysql-5.1.34-pb14/mysql-test/suite/rpl/r/rpl_cross_version.result	Thu Mar 26 19:13:33 2009
+++ /Users/henry/pb/bzr_mysql-5.1-pe-stage/14/mysql-5.1.34-pb14/mysql-test/suite/rpl/r/rpl_cross_version.reject	Fri Mar 27 08:17:05 2009
@@ -2,11 +2,62 @@
 Setting up fake replication from MYSQL_TEST_DIR/suite/binlog/std_data/binlog_old_version_4_1.000001
 ==== Test ====
 start slave sql_thread;
-==== a prove that the fake has been processed successfully ====
-SELECT COUNT(*) - 17920 as zero FROM t3;
-zero
-0
-==== Clean up ====
-stop slave sql_thread;
-Cleaning up after setup_fake_relay_log.inc
-drop table t1, t3;
+**** ERROR: timeout after  seconds while waiting for slave parameter Exec_Master_Log_Pos = 149436 ****
+Current connection is 'default'
+Note: the following output may have changed since the failure was detected
+
+[on default]
+
+**** SHOW SLAVE STATUS on default ****
+SHOW SLAVE STATUS;
+Slave_IO_State	
+Master_Host	dummy.localdomain
+Master_User	test
+Master_Port	3306
+Connect_Retry	60
+Master_Log_File	
+Read_Master_Log_Pos	4
+Relay_Log_File	slave-relay-bin-fake.000001
+Relay_Log_Pos	149413
+Relay_Master_Log_File	
+Slave_IO_Running	No
+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	1290
+Last_Error	Error 'The MySQL server is running with the --slave-load-tmpdir option so it cannot execute this statement' running LOAD DATA INFILE on table 't3'. Default database: 'test'. Failed executing load from '/tmp/pbtmp-n_mix-5/mysqld.1/SQL_LOAD-1-1-2.info'
+Skip_Counter	0
+Exec_Master_Log_Pos	149413
+Relay_Log_Space	149542
+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	1290
+Last_SQL_Error	Error 'The MySQL server is running with the --slave-load-tmpdir option so it cannot execute this statement' running LOAD DATA INFILE on table 't3'. Default database: 'test'. Failed executing load from '/tmp/pbtmp-n_mix-5/mysqld.1/SQL_LOAD-1-1-2.info'
+
+**** SHOW PROCESSLIST on default ****
+SHOW PROCESSLIST;
+Id	User	Host	db	Command	Time	State	Info
+2	root	localhost	test	Query	0	NULL	SHOW PROCESSLIST
+
+**** SHOW BINLOG EVENTS on default ****
+SHOW BINLOG EVENTS IN 'master-bin.000001';
+Log_name	Pos	Event_type	Server_id	End_log_pos	Info
+master-bin.000001	4	Format_desc	1	106	Server ver: 5.1.34-pb14-log, Binlog ver: 4
+Unable to determine master connection. No debug info printed for master.
+Please fix the test case by setting  before sourcing
+show_rpl_debug_info.inc.

mysqltest: In included file "./include/wait_for_slave_param.inc": Result length mismatch

 - saving '/Users/henry/pb/bzr_mysql-5.1-pe-stage/14/mysql-5.1.34-pb14/mysql-test/var-n_mix-5/log/rpl.rpl_cross_version/' to '/Users/henry/pb/bzr_mysql-5.1-pe-stage/14/mysql-5.1.34-pb14/mysql-test/var-n_mix-5/log/rpl.rpl_cross_version/'

Retrying test, attempt(2/3)...

rpl.rpl_cross_version                    [ retry-fail ]
        Test ended at 2009-03-27 06:22:12

CURRENT_TEST: rpl.rpl_cross_version
--- /Users/henry/pb/bzr_mysql-5.1-pe-stage/14/mysql-5.1.34-pb14/mysql-test/suite/rpl/r/rpl_cross_version.result	Thu Mar 26 19:13:33 2009
+++ /Users/henry/pb/bzr_mysql-5.1-pe-stage/14/mysql-5.1.34-pb14/mysql-test/suite/rpl/r/rpl_cross_version.reject	Fri Mar 27 08:22:12 2009
@@ -2,11 +2,62 @@
 Setting up fake replication from MYSQL_TEST_DIR/suite/binlog/std_data/binlog_old_version_4_1.000001
 ==== Test ====
 start slave sql_thread;
-==== a prove that the fake has been processed successfully ====
-SELECT COUNT(*) - 17920 as zero FROM t3;
-zero
-0
-==== Clean up ====
-stop slave sql_thread;
-Cleaning up after setup_fake_relay_log.inc
-drop table t1, t3;
+**** ERROR: timeout after  seconds while waiting for slave parameter Exec_Master_Log_Pos = 149436 ****
+Current connection is 'default'
+Note: the following output may have changed since the failure was detected
+
+[on default]
+
+**** SHOW SLAVE STATUS on default ****
+SHOW SLAVE STATUS;
+Slave_IO_State	
+Master_Host	dummy.localdomain
+Master_User	test
+Master_Port	3306
+Connect_Retry	60
+Master_Log_File	
+Read_Master_Log_Pos	4
+Relay_Log_File	slave-relay-bin-fake.000001
+Relay_Log_Pos	149413
+Relay_Master_Log_File	
+Slave_IO_Running	No
+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	1290
+Last_Error	Error 'The MySQL server is running with the --slave-load-tmpdir option so it cannot execute this statement' running LOAD DATA INFILE on table 't3'. Default database: 'test'. Failed executing load from '/tmp/pbtmp-n_mix-5/mysqld.1/SQL_LOAD-1-1-2.info'
+Skip_Counter	0
+Exec_Master_Log_Pos	149413
+Relay_Log_Space	149542
+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	1290
+Last_SQL_Error	Error 'The MySQL server is running with the --slave-load-tmpdir option so it cannot execute this statement' running LOAD DATA INFILE on table 't3'. Default database: 'test'. Failed executing load from '/tmp/pbtmp-n_mix-5/mysqld.1/SQL_LOAD-1-1-2.info'
+
+**** SHOW PROCESSLIST on default ****
+SHOW PROCESSLIST;
+Id	User	Host	db	Command	Time	State	Info
+2	root	localhost	test	Query	0	NULL	SHOW PROCESSLIST
+
+**** SHOW BINLOG EVENTS on default ****
+SHOW BINLOG EVENTS IN 'master-bin.000001';
+Log_name	Pos	Event_type	Server_id	End_log_pos	Info
+master-bin.000001	4	Format_desc	1	106	Server ver: 5.1.34-pb14-log, Binlog ver: 4
+Unable to determine master connection. No debug info printed for master.
+Please fix the test case by setting  before sourcing
+show_rpl_debug_info.inc.

mysqltest: In included file "./include/wait_for_slave_param.inc": Result length mismatch

 - saving '/Users/henry/pb/bzr_mysql-5.1-pe-stage/14/mysql-5.1.34-pb14/mysql-test/var-n_mix-5/log/rpl.rpl_cross_version/' to '/Users/henry/pb/bzr_mysql-5.1-pe-stage/14/mysql-5.1.34-pb14/mysql-test/var-n_mix-5/log/rpl.rpl_cross_version/'

Test has failed 2 times, no more retries!

Pushed into 5.1.34 (revid:joro@sun.com-20090327143448-wuuuycetc562ty6o) (version source revid:joro@sun.com-20090327121233-j7cof1otutut01nz) (merge vers: 5.1.34) (pib:6)

Pushed into 6.0.11-alpha (revid:alik@sun.com-20090413084402-snnrocwzktcl88ny) (version source revid:joro@sun.com-20090327121728-u9hp8huig35gnddy) (merge vers: 6.0.11-alpha) (pib:6)

Pushed into 5.1.34-ndb-6.2.18 (revid:jonas@mysql.com-20090508185236-p9b3as7qyauybefl) (version source revid:jonas@mysql.com-20090508185236-p9b3as7qyauybefl) (merge vers: 5.1.34-ndb-6.2.18) (pib:6)

Pushed into 5.1.34-ndb-6.3.25 (revid:jonas@mysql.com-20090509063138-1u3q3v09wnn2txyt) (version source revid:jonas@mysql.com-20090509063138-1u3q3v09wnn2txyt) (merge vers: 5.1.34-ndb-6.3.25) (pib:6)

Pushed into 5.1.34-ndb-7.0.6 (revid:jonas@mysql.com-20090509154927-im9a7g846c6u1hzc) (version source revid:jonas@mysql.com-20090509154927-im9a7g846c6u1hzc) (merge vers: 5.1.34-ndb-7.0.6) (pib:6)

See also: BUG#43913.

Duplicated with Bug #43913