Bug #45511 rpl.rpl_binlog_corruption fails with warning messages in Valgrind
Submitted: 15 Jun 2009 23:34 Modified: 9 Jul 2009 12:29
Reporter: Alfranio Correia Email Updates:
Status: Closed Impact on me:
None 
Category:Tests: Replication Severity:S3 (Non-critical)
Version:5.1 OS:Any
Assigned to: Alfranio Correia CPU Architecture:Any
Tags: replication, valgrind
Triage: Triaged: D2 (Serious)

[15 Jun 2009 23:34] Alfranio Correia
Description:
rpl.rpl_binlog_corruption                [ fail ]  Found warnings/errors in server log file!
        Test ended at 2009-06-15 22:32:14
mysqltest: Logging to ''.
mysqltest: Results saved in ''.
mysqltest: Connecting to server localhost:11000 (socket /dev/shm/pbtmp-n_stm-100/mysqld.1.sock) as 'root', connection 'default', attempt 0 ...
mysqltest: ... Connected.
mysqltest: Start processing test commands from './include/check-warnings.test' ...
file_name	line
/dev/shm/var-n_stm-100/log/mysqld.1.err	==29165==    at 0x4A20848: strlen (mc_replace_strmem.c:246)
/dev/shm/var-n_stm-100/log/mysqld.1.err	==29165==    at 0x4A20848: strlen (mc_replace_strmem.c:246)
^ Found warnings!!
mysqltest: ... Done processing test commands.
mysqltest: Test has succeeded!
ok

 - saving '/dev/shm/var-n_stm-100/log/rpl.rpl_binlog_corruption/' to '/dev/shm/var-n_stm-100/log/rpl.rpl_binlog_corruption/'

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

How to repeat:
[valgrind] http://tinyurl.com/create.php
[16 Jun 2009 0:06] Alfranio Correia
Further information on the issue:

090616  2:52:42 [ERROR] Error reading relay log event: slave SQL thread aborted because of I/O error
==26824== Thread 3:
==26824== Conditional jump or move depends on uninitialised value(s)
==26824==    at 0x4026447: strlen (mc_replace_strmem.c:242)
==26824==    by 0x82B2735: Protocol::store(char const*, charset_info_st*) (protocol.cc:702)
==26824==    by 0x846932C: show_master_info(THD*, Master_info*) (slave.cc:1525)
==26824==    by 0x82D3AE0: mysql_execute_command(THD*) (sql_parse.cc:2395)
==26824==    by 0x82DCC78: mysql_parse(THD*, char const*, unsigned, char const**) (sql_parse.cc:5933)
==26824==    by 0x82DDA38: dispatch_command(enum_server_command, THD*, char*, unsigned) (sql_parse.cc:1213)
==26824==    by 0x82DEE9E: do_command(THD*) (sql_parse.cc:854)
==26824==    by 0x82CA891: handle_one_connection (sql_connect.cc:1127)
==26824==    by 0x404450E: start_thread (in /lib/tls/i686/cmov/libpthread-2.8.90.so)
==26824==    by 0x41C3A0D: clone (in /lib/tls/i686/cmov/libc-2.8.90.so)
==26824==
==26824== Conditional jump or move depends on uninitialised value(s)
==26824==    at 0x4026447: strlen (mc_replace_strmem.c:242)
==26824==    by 0x82B2735: Protocol::store(char const*, charset_info_st*) (protocol.cc:702)
==26824==    by 0x8469739: show_master_info(THD*, Master_info*) (slave.cc:1593)
==26824==    by 0x82D3AE0: mysql_execute_command(THD*) (sql_parse.cc:2395)
==26824==    by 0x82DCC78: mysql_parse(THD*, char const*, unsigned, char const**) (sql_parse.cc:5933)
==26824==    by 0x82DDA38: dispatch_command(enum_server_command, THD*, char*, unsigned) (sql_parse.cc:1213)
==26824==    by 0x82DEE9E: do_command(THD*) (sql_parse.cc:854)
==26824==    by 0x82CA891: handle_one_connection (sql_connect.cc:1127)
==26824==    by 0x404450E: start_thread (in /lib/tls/i686/cmov/libpthread-2.8.90.so)
==26824==    by 0x41C3A0D: clone (in /lib/tls/i686/cmov/libc-2.8.90.so)
090616  2:52:42 [ERROR] Slave SQL: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will beable to know their names by issuing 'SHOW SLAVE STATUS' on this slave. Error_code: 1594
090616  2:52:42 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'FIRST' position 0
[16 Jun 2009 1:04] Alfranio Correia
This problem is fixed in 6.0. Either we backport the patch or disable the current test in valdring-5.1.
[16 Jun 2009 9:10] Alfranio Correia
This is the same problem reported in BUG#43076.
[16 Jun 2009 15:37] 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/76403

2944 Alfranio Correia	2009-06-16
      BUG#45511 rpl.rpl_binlog_corruption fails with warning messages in Valgrind
      
      This is a backport of BUG#43076.
[18 Jun 2009 18:35] Alfranio Correia
Pushed to 5.1-bugteam and 6.0-bugteam (null-merge).
[8 Jul 2009 13:30] Bugs System
Pushed into 5.1.37 (revid:joro@sun.com-20090708131116-kyz8iotbum8w9yic) (version source revid:alfranio.correia@sun.com-20090618182514-j6jn19or61oppc7v) (merge vers: 5.1.36) (pib:11)
[9 Jul 2009 7:36] Bugs System
Pushed into 5.1.37 (revid:joro@sun.com-20090708131116-kyz8iotbum8w9yic) (version source revid:alfranio.correia@sun.com-20090618182514-j6jn19or61oppc7v) (merge vers: 5.1.36) (pib:11)
[9 Jul 2009 12:29] Jon Stephens
Documented bugfix in the 5.1.37 changelog as follows:

        The SHOW SLAVE STATUS connection thread competed with the slave 
        SQL thread for use of the error message buffer. As a result, the
        connection thread sometimes received incomplete messages. This issue 
        was uncovered with valgrind when message strings were passed without 
        NULL terminators, causing the error -Conditional jump or move depends 
        on uninitialised value(s)-.

        See also Bug #43076.

Closed.
[10 Jul 2009 11:20] Bugs System
Pushed into 5.4.4-alpha (revid:anozdrin@bk-internal.mysql.com-20090710111017-bnh2cau84ug1hvei) (version source revid:alfranio.correia@sun.com-20090618182943-jmevw7bk9jpwki8p) (merge vers: 5.4.4-alpha) (pib:11)
[26 Aug 2009 13:46] Bugs System
Pushed into 5.1.37-ndb-7.0.8 (revid:jonas@mysql.com-20090826132541-yablppc59e3yb54l) (version source revid:jonas@mysql.com-20090826132541-yablppc59e3yb54l) (merge vers: 5.1.37-ndb-7.0.8) (pib:11)
[26 Aug 2009 13:46] Bugs System
Pushed into 5.1.37-ndb-6.3.27 (revid:jonas@mysql.com-20090826105955-bkj027t47gfbamnc) (version source revid:jonas@mysql.com-20090826105955-bkj027t47gfbamnc) (merge vers: 5.1.37-ndb-6.3.27) (pib:11)
[26 Aug 2009 13:48] Bugs System
Pushed into 5.1.37-ndb-6.2.19 (revid:jonas@mysql.com-20090825194404-37rtosk049t9koc4) (version source revid:jonas@mysql.com-20090825194404-37rtosk049t9koc4) (merge vers: 5.1.37-ndb-6.2.19) (pib:11)
[27 Aug 2009 16:32] Bugs System
Pushed into 5.1.35-ndb-7.1.0 (revid:magnus.blaudd@sun.com-20090827163030-6o3kk6r2oua159hr) (version source revid:jonas@mysql.com-20090826132541-yablppc59e3yb54l) (merge vers: 5.1.37-ndb-7.0.8) (pib:11)