MySQL Bugs: #45511: rpl.rpl_binlog_corruption fails with warning messages in Valgrind

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 Tavares Correia Junior	Email Updates:
Status:	Closed	Impact on me:	None
Category:	Tests: Replication	Severity:	S3 (Non-critical)
Version:	5.1	OS:	Any
Assigned to:	Alfranio Tavares Correia Junior	CPU Architecture:	Any
Tags:	replication, valgrind

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

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

This problem is fixed in 6.0. Either we backport the patch or disable the current test in valdring-5.1.

This is the same problem reported in BUG#43076.

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.

Pushed to 5.1-bugteam and 6.0-bugteam (null-merge).

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)

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)

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.

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)

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)

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)

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)

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)