MySQL Bugs: #37710: rpl.rpl_innodb 'mix' fails sporadically on pushbuild vm-win2003-32-a

Bug #37710	rpl.rpl_innodb 'mix' fails sporadically on pushbuild vm-win2003-32-a
Submitted:	28 Jun 2008 9:17	Modified:	8 Feb 2011 11:36
Reporter:	Sven Sandberg	Email Updates:
Status:	Can't repeat	Impact on me:	None
Category:	Tools: MTR / mysql-test-run	Severity:	S7 (Test Cases)
Version:	6.0	OS:	Any
Assigned to:	Bjørn Munch	CPU Architecture:	Any
Tags:	msgr, pb1, pushbuild, rpl_innodb, sporadic, test failure

Description:
TEST: rpl.rpl_innodb 'mix'

In the test's cleanup code, the slave stopped because a query that failed on master succeeded on slave:

Query caused different errors on master and slave. Error on master: 'Can't find file: '%-.200s' (errno: %d)' (1017), Error on slave: 'no error' (0). Default database: 'mysqltest1'. Query: 'DROP DATABASE mysqltest1'

Why did the query fail on master but still get logged? Errno 1017 is file not found. I *think* it could do this if it gets "file not found" on one of the files in the database, but how could that happen?

It is difficult to analyze since no useful info is left on pushbuild server. If we had the binlogs, it would be much easier.

See also https://inside.mysql.com/mywiki/index.php?title=Replication_Pushbuild_Failures

How to repeat:
WHERE: 6.0/alik on Mon Jun 2 14:18:22 2008/'vm-win2003-32-a' Win32 VS2003 -max-nt/n_mix
URL: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-6.0&order=7

WHERE: 6.0-bugteam/kgeorge on Wed Jun 18 04:25:23 2008/'vm-win2003-32-a' Win32 VS2003 -max-nt/n_mix
 URL: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-6.0-bugteam&order=23

Also found here:

WHERE: 6.0-runtime/konstantin on Fri Jun 27 20:55:30 2008/vm-win2003-32-a/rpl_binlog_row
URL: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-6.0-runtime&order=21
--
WHERE: 6.0-bugteam/kgeorge on Wed Jun 18 04:25:23 2008/vm-win2003-32-a/n_mix
URL: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-6.0-bugteam&order=23
--
WHERE: bk_6.0/gshchepa@bk-internal.mysql.com on Wed May 28 12:02:17 2008/vm-win2003-32-a/ps_stm
URL: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=mysql-6.0&order=85
--
WHERE: 6.0-bugteam/chad on Fri May 23 21:50:33 2008/vm-win2003-32-a/n_stm
URL: https://intranet.mysql.com/secure/pushbuild/showpush.pl?dir=bzr_mysql-6.0-bugteam&order=6

In all locations above, the server log contains this:

============= BEGIN LOG ===============
rpl.rpl_innodb 'stmt'          [ fail ]

=== SHOW MASTER STATUS ===
---- 1. ----
File	slave-bin.000003
Position	200
Binlog_Do_DB	
Binlog_Ignore_DB	
==========================

=== SHOW SLAVE STATUS ===
---- 1. ----
Slave_IO_State	Waiting for master to send event
Master_Host	127.0.0.1
Master_User	root
Master_Port	11000
Connect_Retry	1
Master_Log_File	master-bin.000003
Read_Master_Log_Pos	200
Relay_Log_File	slave-relay-bin.000008
Relay_Log_Pos	254
Relay_Master_Log_File	master-bin.000003
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	0
Last_Error	Query caused different errors on master and slave.     Error on master: 'Can't find file: '%-.200s' (errno: %d)' (1017), Error on slave: 'no error' (0). Default database: 'mysqltest1'. Query: 'DROP DATABASE mysqltest1'
Skip_Counter	0
Exec_Master_Log_Pos	107
Relay_Log_Space	547
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	
Master_SSL_Verify_Server_Cert	No
Last_IO_Errno	0
Last_IO_Error	
Last_SQL_Errno	0
Last_SQL_Error	Query caused different errors on master and slave.     Error on master: 'Can't find file: '%-.200s' (errno: %d)' (1017), Error on slave: 'no error' (0). Default database: 'mysqltest1'. Query: 'DROP DATABASE mysqltest1'
=========================

mysqltest: In included file ".\include\master-slave-end.inc": At line 2: could not sync with master ('select master_pos_wait('master-bin.000003', 200)' returned NULL)

The result from queries just before the failure was:
< snip >
tmp2	CREATE TEMPORARY TABLE `tmp2` (
  `a` int(11) DEFAULT NULL
) ENGINE=MyISAM DEFAULT CHARSET=latin1
SELECT COUNT(*) FROM mysqltest1.t1;
COUNT(*)
0
-------- switch to slave --------
SHOW CREATE TABLE mysqltest1.tmp;
ERROR 42S02: Table 'mysqltest1.tmp' doesn't exist
SHOW CREATE TABLE mysqltest1.tmp2;
ERROR 42S02: Table 'mysqltest1.tmp2' doesn't exist
SELECT COUNT(*) FROM mysqltest1.t1;
COUNT(*)
2
FLUSH LOGS;
-------- switch to master --------
FLUSH LOGS;
DROP DATABASE mysqltest1;
Warnings:
Error	1017	Can't find file: 'proc' (errno: 2)

More results from queries before failure can be found in e:\var-n_stm-100\log\rpl_innodb.log

Stopping All Servers
Restoring snapshot of databases
Resuming Tests
============= END LOG ===============

errno 2 means 'no such file or directory'. So it looks as if the server, during the execution of 'drop database', tries to remove the file 'proc', which does not exist.