Logging: ./mysql-test-run.pl --force rpl.rpl_brow MySQL Version 5.1.52 Checking supported features... - skipping ndbcluster - skipping SSL, mysqld not compiled with SSL Collecting tests... - adding combinations for rpl vardir: /s/bld/5152orig/mysql-test/var Checking leftover processes... Removing old var directory... Creating var directory '/s/bld/5152orig/mysql-test/var'... Installing system database... Using server port 33506 ============================================================================== TEST RESULT TIME (ms) ------------------------------------------------------------ worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009 rpl.rpl_brow 'stmt' [ skipped ] Doesn't support --binlog-format='statement' rpl.rpl_brow 'mix' [ skipped ] Doesn't support --binlog-format='mixed' stop slave; drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; reset master; reset slave; drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; start slave; drop table if exists userstats; drop table if exists userstats2; create table userstats (i int primary key, j int) engine=innodb; create index usx on userstats(j); create table userstats2 (i int primary key, j int) engine=innodb; create index us2x on userstats2(j); show create table userstats; Table Create Table userstats CREATE TABLE `userstats` ( `i` int(11) NOT NULL, `j` int(11) DEFAULT NULL, PRIMARY KEY (`i`), KEY `usx` (`j`) ) ENGINE=InnoDB DEFAULT CHARSET=latin1 insert into userstats values (1,1); insert into userstats values (2,2), (3,3); insert into userstats2 values (4,4); insert into userstats select * from userstats2; replace into userstats value (6,6); replace into userstats value (1,1); delete from userstats where i = 1; delete from userstats where i = 0; on slave, before select * from userstats; i j 2 2 3 3 4 4 6 6 select * from userstats2; i j 4 4 on master, before select * from userstats; i j 2 2 3 3 4 4 6 6 select * from userstats2; i j 4 4 delete userstats, userstats2 from userstats inner join userstats2 where userstats.i = userstats2.i; on master, after select * from userstats; i j 2 2 3 3 6 6 select * from userstats2; i j on slave, after select * from userstats; i j 2 2 3 3 4 4 6 6 select * from userstats2; i j 4 4 rpl.rpl_brow 'row' [ fail ] Test ended at 2011-05-05 10:39:53 CURRENT_TEST: rpl.rpl_brow === SHOW MASTER STATUS === ---- 1. ---- File slave-bin.000001 Position 1786 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 13000 Connect_Retry 1 Master_Log_File master-bin.000001 Read_Master_Log_Pos 2081 Relay_Log_File slave-relay-bin.000003 Relay_Log_Pos 1986 Relay_Master_Log_File master-bin.000001 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 1032 Last_Error Could not execute Delete_rows event on table test.userstats; Can't find record in 'userstats', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 2054 Skip_Counter 0 Exec_Master_Log_Pos 1840 Relay_Log_Space 2382 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 1032 Last_SQL_Error Could not execute Delete_rows event on table test.userstats; Can't find record in 'userstats', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 2054 ========================= === SHOW PROCESSLIST === ---- 1. ---- Id 2 User root Host localhost:58930 db test Command Query Time 0 State Info SHOW PROCESSLIST ---- 2. ---- Id 3 User root Host localhost:58931 db test Command Sleep Time 2 State Info ---- 3. ---- Id 4 User system user Host db Command Connect Time 1 State Waiting for master to send event Info ======================== analyze: sync_with_master mysqltest: At line 90: sync_slave_with_master failed: 'select master_pos_wait('master-bin.000001', 2081, 300)' returned NULL indicating slave SQL thread failure == /s/bld/5152orig/mysql-test/var/tmp/analyze-sync_with_master-mysqld.1.err == SHOW PROCESSLIST; Id User Host db Command Time State Info 5 root localhost:38927 NULL Binlog Dump 1 Has sent all binlog to slave; waiting for binlog to be updated NULL 7 root localhost NULL Query 0 NULL SHOW PROCESSLIST 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.52-log, Binlog ver: 4 master-bin.000001 106 Query 1 199 use `test`; drop table if exists userstats master-bin.000001 199 Query 1 293 use `test`; drop table if exists userstats2 master-bin.000001 293 Query 1 419 use `test`; create table userstats (i int primary key, j int) engine=innodb master-bin.000001 419 Query 1 514 use `test`; create index usx on userstats(j) master-bin.000001 514 Query 1 641 use `test`; create table userstats2 (i int primary key, j int) engine=innodb master-bin.000001 641 Query 1 738 use `test`; create index us2x on userstats2(j) master-bin.000001 738 Query 1 806 BEGIN master-bin.000001 806 Table_map 1 855 table_id: 0 (test.userstats) master-bin.000001 855 Write_rows 1 893 table_id: 0 flags: STMT_END_F master-bin.000001 893 Xid 1 920 COMMIT /* xid=31 */ master-bin.000001 920 Query 1 988 BEGIN master-bin.000001 988 Table_map 1 1037 table_id: 0 (test.userstats) master-bin.000001 1037 Write_rows 1 1084 table_id: 0 flags: STMT_END_F master-bin.000001 1084 Xid 1 1111 COMMIT /* xid=32 */ master-bin.000001 1111 Query 1 1179 BEGIN master-bin.000001 1179 Table_map 1 1229 table_id: 0 (test.userstats2) master-bin.000001 1229 Write_rows 1 1267 table_id: 0 flags: STMT_END_F master-bin.000001 1267 Xid 1 1294 COMMIT /* xid=33 */ master-bin.000001 1294 Query 1 1362 BEGIN master-bin.000001 1362 Table_map 1 1411 table_id: 0 (test.userstats) master-bin.000001 1411 Write_rows 1 1449 table_id: 0 flags: STMT_END_F master-bin.000001 1449 Xid 1 1476 COMMIT /* xid=34 */ master-bin.000001 1476 Query 1 1544 BEGIN master-bin.000001 1544 Table_map 1 1593 table_id: 0 (test.userstats) master-bin.000001 1593 Write_rows 1 1631 table_id: 0 flags: STMT_END_F master-bin.000001 1631 Xid 1 1658 COMMIT /* xid=36 */ master-bin.000001 1658 Query 1 1726 BEGIN master-bin.000001 1726 Table_map 1 1775 table_id: 0 (test.userstats) master-bin.000001 1775 Delete_rows 1 1813 table_id: 0 flags: STMT_END_F master-bin.000001 1813 Xid 1 1840 COMMIT /* xid=40 */ master-bin.000001 1840 Query 1 1908 BEGIN master-bin.000001 1908 Table_map 1 1957 table_id: 0 (test.userstats) master-bin.000001 1957 Table_map 1 2007 table_id: 0 (test.userstats2) master-bin.000001 2007 Delete_rows 1 2054 table_id: 0 flags: STMT_END_F master-bin.000001 2054 Xid 1 2081 COMMIT /* xid=47 */ == /s/bld/5152orig/mysql-test/var/tmp/analyze-sync_with_master-mysqld.2.err == SHOW PROCESSLIST; Id User Host db Command Time State Info 4 system user NULL Connect 1 Waiting for master to send event NULL 6 root localhost NULL Query 0 NULL SHOW PROCESSLIST SHOW BINLOG EVENTS IN 'slave-bin.000001'; Log_name Pos Event_type Server_id End_log_pos Info slave-bin.000001 4 Format_desc 2 106 Server ver: 5.1.52-log, Binlog ver: 4 slave-bin.000001 106 Query 1 199 use `test`; drop table if exists userstats slave-bin.000001 199 Query 1 293 use `test`; drop table if exists userstats2 slave-bin.000001 293 Query 1 419 use `test`; create table userstats (i int primary key, j int) engine=innodb slave-bin.000001 419 Query 1 514 use `test`; create index usx on userstats(j) slave-bin.000001 514 Query 1 641 use `test`; create table userstats2 (i int primary key, j int) engine=innodb slave-bin.000001 641 Query 1 738 use `test`; create index us2x on userstats2(j) slave-bin.000001 738 Query 1 797 BEGIN slave-bin.000001 797 Table_map 1 846 table_id: 0 (test.userstats) slave-bin.000001 846 Write_rows 1 884 table_id: 0 flags: STMT_END_F slave-bin.000001 884 Xid 1 911 COMMIT /* xid=37 */ slave-bin.000001 911 Query 1 970 BEGIN slave-bin.000001 970 Table_map 1 1019 table_id: 0 (test.userstats) slave-bin.000001 1019 Write_rows 1 1066 table_id: 0 flags: STMT_END_F slave-bin.000001 1066 Xid 1 1093 COMMIT /* xid=39 */ slave-bin.000001 1093 Query 1 1152 BEGIN slave-bin.000001 1152 Table_map 1 1202 table_id: 0 (test.userstats2) slave-bin.000001 1202 Write_rows 1 1240 table_id: 0 flags: STMT_END_F slave-bin.000001 1240 Xid 1 1267 COMMIT /* xid=41 */ slave-bin.000001 1267 Query 1 1326 BEGIN slave-bin.000001 1326 Table_map 1 1375 table_id: 0 (test.userstats) slave-bin.000001 1375 Write_rows 1 1413 table_id: 0 flags: STMT_END_F slave-bin.000001 1413 Xid 1 1440 COMMIT /* xid=43 */ slave-bin.000001 1440 Query 1 1499 BEGIN slave-bin.000001 1499 Table_map 1 1548 table_id: 0 (test.userstats) slave-bin.000001 1548 Write_rows 1 1586 table_id: 0 flags: STMT_END_F slave-bin.000001 1586 Xid 1 1613 COMMIT /* xid=46 */ slave-bin.000001 1613 Query 1 1672 BEGIN slave-bin.000001 1672 Table_map 1 1721 table_id: 0 (test.userstats) slave-bin.000001 1721 Delete_rows 1 1759 table_id: 0 flags: STMT_END_F slave-bin.000001 1759 Xid 1 1786 COMMIT /* xid=50 */ - saving '/s/bld/5152orig/mysql-test/var/log/rpl.rpl_brow-row/' to '/s/bld/5152orig/mysql-test/var/log/rpl.rpl_brow-row/' Retrying test, attempt(2/3)... stop slave; drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; reset master; reset slave; drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; start slave; drop table if exists userstats; drop table if exists userstats2; create table userstats (i int primary key, j int) engine=innodb; create index usx on userstats(j); create table userstats2 (i int primary key, j int) engine=innodb; create index us2x on userstats2(j); show create table userstats; Table Create Table userstats CREATE TABLE `userstats` ( `i` int(11) NOT NULL, `j` int(11) DEFAULT NULL, PRIMARY KEY (`i`), KEY `usx` (`j`) ) ENGINE=InnoDB DEFAULT CHARSET=latin1 insert into userstats values (1,1); insert into userstats values (2,2), (3,3); insert into userstats2 values (4,4); insert into userstats select * from userstats2; replace into userstats value (6,6); replace into userstats value (1,1); delete from userstats where i = 1; delete from userstats where i = 0; on slave, before select * from userstats; i j 2 2 3 3 4 4 6 6 select * from userstats2; i j 4 4 on master, before select * from userstats; i j 2 2 3 3 4 4 6 6 select * from userstats2; i j 4 4 delete userstats, userstats2 from userstats inner join userstats2 where userstats.i = userstats2.i; on master, after select * from userstats; i j 2 2 3 3 6 6 select * from userstats2; i j on slave, after select * from userstats; i j 2 2 3 3 4 4 6 6 select * from userstats2; i j 4 4 rpl.rpl_brow 'row' [ retry-fail ] Test ended at 2011-05-05 10:39:56 CURRENT_TEST: rpl.rpl_brow === SHOW MASTER STATUS === ---- 1. ---- File slave-bin.000001 Position 1786 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 13000 Connect_Retry 1 Master_Log_File master-bin.000001 Read_Master_Log_Pos 2081 Relay_Log_File slave-relay-bin.000003 Relay_Log_Pos 1986 Relay_Master_Log_File master-bin.000001 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 1032 Last_Error Could not execute Delete_rows event on table test.userstats; Can't find record in 'userstats', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 2054 Skip_Counter 0 Exec_Master_Log_Pos 1840 Relay_Log_Space 2382 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 1032 Last_SQL_Error Could not execute Delete_rows event on table test.userstats; Can't find record in 'userstats', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 2054 ========================= === SHOW PROCESSLIST === ---- 1. ---- Id 2 User root Host localhost:58941 db test Command Query Time 0 State Info SHOW PROCESSLIST ---- 2. ---- Id 3 User root Host localhost:58942 db test Command Sleep Time 2 State Info ---- 3. ---- Id 4 User system user Host db Command Connect Time 2 State Waiting for master to send event Info ======================== analyze: sync_with_master mysqltest: At line 90: sync_slave_with_master failed: 'select master_pos_wait('master-bin.000001', 2081, 300)' returned NULL indicating slave SQL thread failure == /s/bld/5152orig/mysql-test/var/tmp/analyze-sync_with_master-mysqld.1.err == SHOW PROCESSLIST; Id User Host db Command Time State Info 5 root localhost:38938 NULL Binlog Dump 2 Has sent all binlog to slave; waiting for binlog to be updated NULL 7 root localhost NULL Query 0 NULL SHOW PROCESSLIST 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.52-log, Binlog ver: 4 master-bin.000001 106 Query 1 199 use `test`; drop table if exists userstats master-bin.000001 199 Query 1 293 use `test`; drop table if exists userstats2 master-bin.000001 293 Query 1 419 use `test`; create table userstats (i int primary key, j int) engine=innodb master-bin.000001 419 Query 1 514 use `test`; create index usx on userstats(j) master-bin.000001 514 Query 1 641 use `test`; create table userstats2 (i int primary key, j int) engine=innodb master-bin.000001 641 Query 1 738 use `test`; create index us2x on userstats2(j) master-bin.000001 738 Query 1 806 BEGIN master-bin.000001 806 Table_map 1 855 table_id: 0 (test.userstats) master-bin.000001 855 Write_rows 1 893 table_id: 0 flags: STMT_END_F master-bin.000001 893 Xid 1 920 COMMIT /* xid=31 */ master-bin.000001 920 Query 1 988 BEGIN master-bin.000001 988 Table_map 1 1037 table_id: 0 (test.userstats) master-bin.000001 1037 Write_rows 1 1084 table_id: 0 flags: STMT_END_F master-bin.000001 1084 Xid 1 1111 COMMIT /* xid=32 */ master-bin.000001 1111 Query 1 1179 BEGIN master-bin.000001 1179 Table_map 1 1229 table_id: 0 (test.userstats2) master-bin.000001 1229 Write_rows 1 1267 table_id: 0 flags: STMT_END_F master-bin.000001 1267 Xid 1 1294 COMMIT /* xid=33 */ master-bin.000001 1294 Query 1 1362 BEGIN master-bin.000001 1362 Table_map 1 1411 table_id: 0 (test.userstats) master-bin.000001 1411 Write_rows 1 1449 table_id: 0 flags: STMT_END_F master-bin.000001 1449 Xid 1 1476 COMMIT /* xid=34 */ master-bin.000001 1476 Query 1 1544 BEGIN master-bin.000001 1544 Table_map 1 1593 table_id: 0 (test.userstats) master-bin.000001 1593 Write_rows 1 1631 table_id: 0 flags: STMT_END_F master-bin.000001 1631 Xid 1 1658 COMMIT /* xid=36 */ master-bin.000001 1658 Query 1 1726 BEGIN master-bin.000001 1726 Table_map 1 1775 table_id: 0 (test.userstats) master-bin.000001 1775 Delete_rows 1 1813 table_id: 0 flags: STMT_END_F master-bin.000001 1813 Xid 1 1840 COMMIT /* xid=40 */ master-bin.000001 1840 Query 1 1908 BEGIN master-bin.000001 1908 Table_map 1 1957 table_id: 0 (test.userstats) master-bin.000001 1957 Table_map 1 2007 table_id: 0 (test.userstats2) master-bin.000001 2007 Delete_rows 1 2054 table_id: 0 flags: STMT_END_F master-bin.000001 2054 Xid 1 2081 COMMIT /* xid=47 */ == /s/bld/5152orig/mysql-test/var/tmp/analyze-sync_with_master-mysqld.2.err == SHOW PROCESSLIST; Id User Host db Command Time State Info 4 system user NULL Connect 2 Waiting for master to send event NULL 6 root localhost NULL Query 0 NULL SHOW PROCESSLIST SHOW BINLOG EVENTS IN 'slave-bin.000001'; Log_name Pos Event_type Server_id End_log_pos Info slave-bin.000001 4 Format_desc 2 106 Server ver: 5.1.52-log, Binlog ver: 4 slave-bin.000001 106 Query 1 199 use `test`; drop table if exists userstats slave-bin.000001 199 Query 1 293 use `test`; drop table if exists userstats2 slave-bin.000001 293 Query 1 419 use `test`; create table userstats (i int primary key, j int) engine=innodb slave-bin.000001 419 Query 1 514 use `test`; create index usx on userstats(j) slave-bin.000001 514 Query 1 641 use `test`; create table userstats2 (i int primary key, j int) engine=innodb slave-bin.000001 641 Query 1 738 use `test`; create index us2x on userstats2(j) slave-bin.000001 738 Query 1 797 BEGIN slave-bin.000001 797 Table_map 1 846 table_id: 0 (test.userstats) slave-bin.000001 846 Write_rows 1 884 table_id: 0 flags: STMT_END_F slave-bin.000001 884 Xid 1 911 COMMIT /* xid=37 */ slave-bin.000001 911 Query 1 970 BEGIN slave-bin.000001 970 Table_map 1 1019 table_id: 0 (test.userstats) slave-bin.000001 1019 Write_rows 1 1066 table_id: 0 flags: STMT_END_F slave-bin.000001 1066 Xid 1 1093 COMMIT /* xid=40 */ slave-bin.000001 1093 Query 1 1152 BEGIN slave-bin.000001 1152 Table_map 1 1202 table_id: 0 (test.userstats2) slave-bin.000001 1202 Write_rows 1 1240 table_id: 0 flags: STMT_END_F slave-bin.000001 1240 Xid 1 1267 COMMIT /* xid=42 */ slave-bin.000001 1267 Query 1 1326 BEGIN slave-bin.000001 1326 Table_map 1 1375 table_id: 0 (test.userstats) slave-bin.000001 1375 Write_rows 1 1413 table_id: 0 flags: STMT_END_F slave-bin.000001 1413 Xid 1 1440 COMMIT /* xid=44 */ slave-bin.000001 1440 Query 1 1499 BEGIN slave-bin.000001 1499 Table_map 1 1548 table_id: 0 (test.userstats) slave-bin.000001 1548 Write_rows 1 1586 table_id: 0 flags: STMT_END_F slave-bin.000001 1586 Xid 1 1613 COMMIT /* xid=46 */ slave-bin.000001 1613 Query 1 1672 BEGIN slave-bin.000001 1672 Table_map 1 1721 table_id: 0 (test.userstats) slave-bin.000001 1721 Delete_rows 1 1759 table_id: 0 flags: STMT_END_F slave-bin.000001 1759 Xid 1 1786 COMMIT /* xid=50 */ - saving '/s/bld/5152orig/mysql-test/var/log/rpl.rpl_brow-row/' to '/s/bld/5152orig/mysql-test/var/log/rpl.rpl_brow-row/' Test has failed 2 times, no more retries! ------------------------------------------------------------ The servers were restarted 1 times Spent 0.000 of 7 seconds executing testcases Completed: Failed 1/1 tests, 0.00% were successful. Failing test(s): rpl.rpl_brow The log files in var/log may give you some hint of what went wrong. If you want to report this error, please read first the documentation at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html mysql-test-run: *** ERROR: there were failing test cases