Bug #58762 rpl.rpl_packet fails in the weekly PB2 run
Submitted: 6 Dec 2010 17:23 Modified: 6 Jan 2011 4:55
Reporter: Anitha Gopi Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Row Based Replication ( RBR ) Severity:S3 (Non-critical)
Version:5.6 OS:Any
Assigned to: Luis Soares CPU Architecture:Any

[6 Dec 2010 17:23] Anitha Gopi
Description:
rpl.rpl_packet 'row' [ fail ]
        Test ended at 2010-12-03 00:21:09

CURRENT_TEST: rpl.rpl_packet
--- /export/home3/pb2/test/sb_2-2624024-1291330982.65/mysql-5.6.1-m5-linux-x86_64-test/mysql-test/suite/rpl/r/rpl_packet.result	2010-12-02 21:15:38.000000000 +0300
+++ /export/home3/pb2/test/sb_2-2624024-1291330982.65/mysql-5.6.1-m5-linux-x86_64-test/mysql-test/suite/rpl/r/rpl_packet.reject	2010-12-03 02:21:09.000000000 +0300
@@ -78,8 +78,67 @@
 # Record Read_Master_Log_Pos for the Table_map_log_event
 SET @@global.max_allowed_packet=1048576;
 SET @b55790_output.1= LOAD_FILE('MYSQLTEST_VARDIR/tmp/b55790-mysqlbinlog.1');
+**** ERROR **** Table map 'end_log_pos 445 Table_map' NOT FOUND in mysqlbinlog output (--start-position=485 --base64-output=decode-rows -v /export/home3/pb2/test/sb_2-2624024-1291330982.65/mysql-5.6.1-m5-linux-x86_64-test/mysql-test/var-all_binlog_checksum/tmp/b55790-mysqlbinlog.1).
+/*!40019 SET @@session.max_insert_delayed_threads=0*/;
+/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
+DELIMITER /*!*/;
+# at 485
+#101203  2:21:09 server id 1  end_log_pos 399 CRC32 0x3370088c 	Query	thread_id=9	exec_time=0	error_code=0
+SET TIMESTAMP=1291332069/*!*/;
+SET @@session.pseudo_thread_id=9/*!*/;
+SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
+SET @@session.sql_mode=0/*!*/;
+SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
+/*!\C latin1 *//*!*/;
+SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
+SET @@session.lc_time_names=0/*!*/;
+SET @@session.collation_database=DEFAULT/*!*/;
+BEGIN
+/*!*/;
+# at 557
+#101203  2:21:09 server id 1  end_log_pos 445 CRC32 0xde87e330 	Table_map: `test`.`t1` mapped to number 55
+DELIMITER ;
+# End of log file
+ROLLBACK /* added by mysqlbinlog */;
+/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
 WARNING: The range of printed events ends with a row event or a table map event that does not have the STMT_END_F flag set. This might be because the last statement was not fully written to the log, or because you are using a --stop-position or --stop-datetime that refers to an event in the middle of a statement. The event(s) from the partial statement have not been written to output.
 SET @b55790_output.1= LOAD_FILE('MYSQLTEST_VARDIR/tmp/b55790-mysqlbinlog.1');
+**** ERROR **** Table map 'end_log_pos 445 Table_map' NOT FOUND in mysqlbinlog output (--start-position=485 /export/home3/pb2/test/sb_2-2624024-1291330982.65/mysql-5.6.1-m5-linux-x86_64-test/mysql-test/var-all_binlog_checksum/tmp/b55790-mysqlbinlog.1).
+/*!40019 SET @@session.max_insert_delayed_threads=0*/;
+/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
+DELIMITER /*!*/;
+# at 4
+#101203  2:21:08 server id 2  end_log_pos 114 CRC32 0xd648d7ca 	Start: binlog v 4, server v 5.6.1-m5-log created 101203  2:21:08
+BINLOG '
+5Cn4TA8CAAAAbgAAAHIAAABAAAQANS42LjEtbTUtbG9nAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
+AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAVgAEGggAAAAICAgCAAAAAcrXSNY=
+'/*!*/;
+# at 162
+#101203  2:21:08 server id 1  end_log_pos 114 CRC32 0x1f624d14 	Start: binlog v 4, server v 5.6.1-m5-log created 101203  2:21:08 at startup
+ROLLBACK/*!*/;
+BINLOG '
+5Cn4TA8BAAAAbgAAAHIAAAAAAAQANS42LjEtbTUtbG9nAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
+AAAAAAAAAAAAAAAAAADkKfhMEzgNAAgAEgAEBAQEEgAAVgAEGggAAAAICAgCAAAAARRNYh8=
+'/*!*/;
+# at 485
+#101203  2:21:09 server id 1  end_log_pos 399 CRC32 0x3370088c 	Query	thread_id=9	exec_time=0	error_code=0
+SET TIMESTAMP=1291332069/*!*/;
+SET @@session.pseudo_thread_id=9/*!*/;
+SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
+SET @@session.sql_mode=0/*!*/;
+SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
+/*!\C latin1 *//*!*/;
+SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
+SET @@session.lc_time_names=0/*!*/;
+SET @@session.collation_database=DEFAULT/*!*/;
+BEGIN
+/*!*/;
+# at 557
+#101203  2:21:09 server id 1  end_log_pos 445 CRC32 0xde87e330 	Table_map: `test`.`t1` mapped to number 55
+DELIMITER ;
+# End of log file
+ROLLBACK /* added by mysqlbinlog */;
+/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
 WARNING: The range of printed events ends with a row event or a table map event that does not have the STMT_END_F flag set. This might be because the last statement was not fully written to the log, or because you are using a --stop-position or --stop-datetime that refers to an event in the middle of a statement. The event(s) from the partial statement have not been written to output.
 ==== clean up ====
 DROP TABLE t1;

mysqltest: Result content mismatch

 - saving '/export/home3/pb2/test/sb_2-2624024-1291330982.65/mysql-5.6.1-m5-linux-x86_64-test/mysql-test/var-all_binlog_checksum/log/rpl.rpl_packet-row/' to '/export/home3/pb2/test/sb_2-2624024-1291330982.65/mysql-5.6.1-m5-linux-x86_64-test/mysql-test/var-all_binlog_checksum/log/rpl.rpl_packet-row/'

How to repeat:
See the PB2 results for weekly-trunk-bugfixing

http://pb2.norway.sun.com/?action=archive_download&archive_id=2625492&pretty=please
[7 Dec 2010 1:45] Luis Soares
Caused by patch for BUG#55790. The test needs some rewrite so that it
passes seamlessly when checksums are active.

There is one assertion in the test case that depends an exact match on
mysqlbinlog output. When checksums are ON, this will fail, because a
string containing the event checksum is also output.
[7 Dec 2010 1:49] Bugs System
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/126177

3417 Luis Soares	2010-12-07
      BUG#58762: rpl.rpl_packet fails in the weekly PB2 run
      
      The test contains an assertion that depends on an exact
      match on mysqlbinlog output. However, mysqlbinlog output
      changes when checksums are ON, because it adds the 
      checksum description as well. This makes the test case to
      fail when running it with --mysqld=--binlog-checksum=...
      
      The fix is to rewrite the assertion so that the pattern
      matching is made crc agnostic. To do this we resort to
      perl instead of mysql text function INSTR.
[7 Dec 2010 14:41] Bugs System
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/126216

3420 Luis Soares	2010-12-07 [merge]
      BUG#58762
      
      Autmoerged bzr bundle from bug report into latest 
      mysql-trunk-bugfixing.
[7 Dec 2010 14:44] Luis Soares
Queued in mysql-trunk-bugfixing.
[17 Dec 2010 12:57] Bugs System
Pushed into mysql-trunk 5.6.1 (revid:georgi.kodinov@oracle.com-20101217125013-y8pb3az32rtbplc9) (version source revid:anitha.gopi@sun.com-20101210041312-50t9adyhwwybsm6x) (merge vers: 5.6.1) (pib:24)
[6 Jan 2011 4:55] Jon Stephens
Changes to test code only; no changelog entry required. Closed.