/// How to repeat [ushastry@ushastry mysql-test]$ cat t/69831.test --source include/master-slave.inc --source include/have_binlog_format_row.inc CREATE TABLE t1 (f1 VARCHAR(128), f2 VARCHAR(128), KEY (f2,f1) USING BTREE) ENGINE=MEMORY; INSERT INTO t1 VALUES (NULL,'not'),('one',NULL),('two',NULL),('three',''); UPDATE t1 SET f2 = 'new'; --sync_slave_with_master // 5.5.33 [ushastry@ushastry mysql-test]$ ./mysql-test-run.pl 69831 --mysqld=--binlog_format=row Logging: ./mysql-test-run.pl 69831 --mysqld=--binlog_format=row MySQL Version 5.5.33 Using binlog format 'row' Checking supported features... - skipping SSL, mysqld not compiled with SSL - binaries are debug compiled Collecting tests... Checking leftover processes... Removing old var directory... Creating var directory '/home/ushastry/mybuilds/mysql-5.5.33/mysql-test/var'... Installing system database... Using server port 41794 ============================================================================== TEST RESULT TIME (ms) or COMMENT -------------------------------------------------------------------------- worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009 include/master-slave.inc [connection master] CREATE TABLE t1 (f1 VARCHAR(128), f2 VARCHAR(128), KEY (f2,f1) USING BTREE) ENGINE=MEMORY; INSERT INTO t1 VALUES (NULL,'not'),('one',NULL),('two',NULL),('three',''); UPDATE t1 SET f2 = 'new'; main.69831 [ fail ] Test ended at 2013-07-25 19:09:00 CURRENT_TEST: main.69831 === SHOW MASTER STATUS === ---- 1. ---- File slave-bin.000001 Position 681 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 764 Relay_Log_File slave-relay-bin.000002 Relay_Log_Pos 641 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 Update_rows event on table test.t1; Can't find record in 't1', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 695 Skip_Counter 0 Exec_Master_Log_Pos 494 Relay_Log_Space 1067 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 Update_rows event on table test.t1; Can't find record in 't1', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 695 Replicate_Ignore_Server_Ids Master_Server_Id 1 ========================= === SHOW PROCESSLIST === ---- 1. ---- Id 2 User root Host localhost:55039 db test Command Sleep Time 0 State Info ---- 2. ---- Id 3 User root Host localhost:55040 db test Command Sleep Time 0 State Info ---- 3. ---- Id 4 User system user Host db Command Connect Time 0 State Waiting for master to send event Info ---- 4. ---- Id 6 User root Host localhost:55046 db test Command Query Time 0 State Info SHOW PROCESSLIST ---- 5. ---- Id 7 User root Host localhost:55047 db test Command Sleep Time 0 State Info ======================== analyze: sync_with_master mysqltest: At line 9: sync_slave_with_master failed: 'select master_pos_wait('master-bin.000001', 764, 300)' returned NULL indicating slave SQL thread failure == /home/ushastry/mybuilds/mysql-5.5.33/mysql-test/var/tmp/analyze-sync_with_master-mysqld.1.err == ############################## default ############################## **** SHOW WARNINGS on default **** SHOW WARNINGS; Level Code Message **** SELECT replication-related variables on default **** SELECT NOW(), @@SERVER_ID; NOW() @@SERVER_ID 2013-07-25 16:39:00 1 **** SHOW SLAVE STATUS on default **** SHOW SLAVE STATUS; **** SHOW MASTER STATUS on default **** SHOW MASTER STATUS; File master-bin.000001 Position 764 Binlog_Do_DB Binlog_Ignore_DB **** SHOW SLAVE HOSTS on default **** SHOW SLAVE HOSTS; Server_id 2 Host 127.0.0.1 Port 13001 Master_id 1 **** SHOW PROCESSLIST on default **** SHOW PROCESSLIST; Id User Host db Command Time State Info 5 root localhost:33598 NULL Binlog Dump 0 Master has sent all binlog to slave; waiting for binlog to be updated NULL 8 root localhost NULL Query 0 NULL SHOW PROCESSLIST **** SHOW BINARY LOGS on default **** SHOW BINARY LOGS; Log_name File_size master-bin.000001 764 **** SHOW BINLOG EVENTS on default **** binlog_name = 'master-bin.000001' 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 107 Server ver: 5.5.33-debug-log, Binlog ver: 4 master-bin.000001 107 Query 1 259 use `test`; CREATE TABLE t1 (f1 VARCHAR(128), f2 VARCHAR(128), KEY (f2,f1) USING BTREE) ENGINE=MEMORY master-bin.000001 259 Query 1 327 BEGIN master-bin.000001 327 Table_map 1 373 table_id: 41 (test.t1) master-bin.000001 373 Write_rows 1 425 table_id: 41 flags: STMT_END_F master-bin.000001 425 Query 1 494 COMMIT master-bin.000001 494 Query 1 562 BEGIN master-bin.000001 562 Table_map 1 608 table_id: 41 (test.t1) master-bin.000001 608 Update_rows 1 695 table_id: 41 flags: STMT_END_F master-bin.000001 695 Query 1 764 COMMIT **** SHOW RELAYLOG EVENTS on default **** relaylog_name = 'No such row' SHOW RELAYLOG EVENTS IN 'No such row'; Log_name Pos Event_type Server_id End_log_pos Info == /home/ushastry/mybuilds/mysql-5.5.33/mysql-test/var/tmp/analyze-sync_with_master-mysqld.2.err == ############################## default ############################## **** SHOW WARNINGS on default **** SHOW WARNINGS; Level Code Message **** SELECT replication-related variables on default **** SELECT NOW(), @@SERVER_ID; NOW() @@SERVER_ID 2013-07-25 16:39:00 2 **** SHOW SLAVE STATUS on default **** SHOW SLAVE STATUS; 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 764 Relay_Log_File slave-relay-bin.000002 Relay_Log_Pos 641 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 Update_rows event on table test.t1; Can't find record in 't1', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 695 Skip_Counter 0 Exec_Master_Log_Pos 494 Relay_Log_Space 1067 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 1032 Last_SQL_Error Could not execute Update_rows event on table test.t1; Can't find record in 't1', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log master-bin.000001, end_log_pos 695 Replicate_Ignore_Server_Ids Master_Server_Id 1 **** SHOW MASTER STATUS on default **** SHOW MASTER STATUS; File slave-bin.000001 Position 681 Binlog_Do_DB Binlog_Ignore_DB **** SHOW SLAVE HOSTS on default **** SHOW SLAVE HOSTS; **** SHOW PROCESSLIST on default **** SHOW PROCESSLIST; Id User Host db Command Time State Info 4 system user NULL Connect 0 Waiting for master to send event NULL 8 root localhost NULL Query 0 NULL SHOW PROCESSLIST **** SHOW BINARY LOGS on default **** SHOW BINARY LOGS; Log_name File_size slave-bin.000001 681 **** SHOW BINLOG EVENTS on default **** binlog_name = 'slave-bin.000001' 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 107 Server ver: 5.5.33-debug-log, Binlog ver: 4 slave-bin.000001 107 Query 1 259 use `test`; CREATE TABLE t1 (f1 VARCHAR(128), f2 VARCHAR(128), KEY (f2,f1) USING BTREE) ENGINE=MEMORY slave-bin.000001 259 Query 1 318 BEGIN slave-bin.000001 318 Table_map 1 364 table_id: 41 (test.t1) slave-bin.000001 364 Write_rows 1 416 table_id: 41 flags: STMT_END_F slave-bin.000001 416 Query 1 476 COMMIT slave-bin.000001 476 Query 1 535 BEGIN slave-bin.000001 535 Table_map 1 581 table_id: 41 (test.t1) slave-bin.000001 581 Update_rows 1 621 table_id: 41 flags: STMT_END_F slave-bin.000001 621 Query 1 681 COMMIT **** SHOW RELAYLOG EVENTS on default **** relaylog_name = 'slave-relay-bin.000002' SHOW RELAYLOG EVENTS IN 'slave-relay-bin.000002'; Log_name Pos Event_type Server_id End_log_pos Info slave-relay-bin.000002 4 Format_desc 2 107 Server ver: 5.5.33-debug-log, Binlog ver: 4 slave-relay-bin.000002 107 Rotate 1 0 master-bin.000001;pos=4 slave-relay-bin.000002 151 Format_desc 1 107 Server ver: 5.5.33-debug-log, Binlog ver: 4 slave-relay-bin.000002 254 Query 1 259 use `test`; CREATE TABLE t1 (f1 VARCHAR(128), f2 VARCHAR(128), KEY (f2,f1) USING BTREE) ENGINE=MEMORY slave-relay-bin.000002 406 Query 1 327 BEGIN slave-relay-bin.000002 474 Table_map 1 373 table_id: 41 (test.t1) slave-relay-bin.000002 520 Write_rows 1 425 table_id: 41 flags: STMT_END_F slave-relay-bin.000002 572 Query 1 494 COMMIT slave-relay-bin.000002 641 Query 1 562 BEGIN slave-relay-bin.000002 709 Table_map 1 608 table_id: 41 (test.t1) slave-relay-bin.000002 755 Update_rows 1 695 table_id: 41 flags: STMT_END_F slave-relay-bin.000002 842 Query 1 764 COMMIT - saving '/home/ushastry/mybuilds/mysql-5.5.33/mysql-test/var/log/main.69831/' to '/home/ushastry/mybuilds/mysql-5.5.33/mysql-test/var/log/main.69831/' -------------------------------------------------------------------------- The servers were restarted 0 times Spent 0.000 of 8 seconds executing testcases Completed: Failed 1/1 tests, 0.00% were successful. Failing test(s): main.69831 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 [ushastry@ushastry mysql-test]$ // 5.6.13 [ushastry@ushastry mysql-test]$ ./mysql-test-run.pl 69831 --mysqld=--binlog_format=row Logging: ./mysql-test-run.pl 69831 --mysqld=--binlog_format=row 2013-07-25 19:30:27 29395 [Warning] Buffered warning: Changed limits: max_open_files: 1024 (requested 5000) 2013-07-25 19:30:27 29395 [Warning] Buffered warning: Changed limits: table_cache: 431 (requested 2000) 2013-07-25 19:30:27 29395 [Note] Plugin 'FEDERATED' is disabled. 2013-07-25 19:30:27 29395 [Note] Binlog end 2013-07-25 19:30:27 29395 [Note] Shutting down plugin 'CSV' 2013-07-25 19:30:27 29395 [Note] Shutting down plugin 'MyISAM' MySQL Version 5.6.13 Using binlog format 'row' Checking supported features... - SSL connections supported - binaries are debug compiled Collecting tests... Removing old var directory... Creating var directory '/home/ushastry/mybuilds/mysql-5.6.13/mysql-test/var'... Installing system database... Using server port 36653 ============================================================================== TEST RESULT TIME (ms) or COMMENT -------------------------------------------------------------------------- worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009 include/master-slave.inc Warnings: Note #### Sending passwords in plain text without SSL/TLS is extremely insecure. Note #### Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information. [connection master] CREATE TABLE t1 (f1 VARCHAR(128), f2 VARCHAR(128), KEY (f2,f1) USING BTREE) ENGINE=MEMORY; INSERT INTO t1 VALUES (NULL,'not'),('one',NULL),('two',NULL),('three',''); UPDATE t1 SET f2 = 'new'; main.69831 [ pass ] 532 MTR's internal check of the test case 'main.69831' failed. This means that the test case does not preserve the state that existed before the test case was executed. Most likely the test case did not do a proper clean-up. It could also be caused by the previous test run by this thread, if the server wasn't restarted. This is the diff of the states of the servers before and after the test case was executed: mysqltest: Logging to '/home/ushastry/mybuilds/mysql-5.6.13/mysql-test/var/tmp/check-mysqld_1.log'. mysqltest: Results saved in '/home/ushastry/mybuilds/mysql-5.6.13/mysql-test/var/tmp/check-mysqld_1.result'. mysqltest: Connecting to server localhost:13000 (socket /home/ushastry/mybuilds/mysql-5.6.13/mysql-test/var/tmp/mysqld.1.sock) as 'root', connection 'default', attempt 0 ... mysqltest: ... Connected. mysqltest: Start processing test commands from './include/check-testcase.test' ... mysqltest: ... Done processing test commands. --- /home/ushastry/mybuilds/mysql-5.6.13/mysql-test/var/tmp/check-mysqld_1.result 2013-07-25 17:00:36.012172016 +0300 +++ /home/ushastry/mybuilds/mysql-5.6.13/mysql-test/var/tmp/check-mysqld_1.reject 2013-07-25 17:00:36.995107130 +0300 @@ -516,6 +516,7 @@ def performance_schema utf8 utf8_general_ci NULL def test latin1 latin1_swedish_ci NULL tables_in_test +t1 tables_in_mysql mysql.columns_priv mysql.db mysqltest: Result content mismatch not ok -------------------------------------------------------------------------- The servers were restarted 0 times Spent 0.532 of 13 seconds executing testcases Check of testcase failed for: main.69831 Completed: All 1 tests were successful.