Bug #51019 crash/invalid memory accesses after an error occurs with binlogging
Submitted: 9 Feb 2010 9:25 Modified: 30 Mar 2010 8:50
Reporter: Shane Bester (Platinum Quality Contributor) Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Replication Severity:S1 (Critical)
Version:5.1.43, 5.1.45-bzr OS:Any
Assigned to: Assigned Account CPU Architecture:Any
Tags: assertion, crash, valgrind

[9 Feb 2010 9:25] Shane Bester
Description:
If binlogging encounters an error, server crash can happen due to many errors:
5.1.43 valgrind output:

Invalid write of size 1
at: memcpy (mc_replace_strmem.c:482)
by: my_b_safe_write (mf_iocache.c:1625)
by: Log_event::write_header (log_event.cc:959)
by: Query_log_event::write (log_event.cc:2329)
by: MYSQL_BIN_LOG::write(Log_event*) (log.cc:4387)
by: THD::binlog_query( (sql_class.cc:3909)
by: mysql_insert (sql_insert.cc:921)
by: mysql_execute_command(THD*) (sql_parse.cc:3181)
by: mysql_parse (sql_parse.cc:5961)
by: dispatch_command (sql_parse.cc:1233)
by: do_command(THD*) (sql_parse.cc:874)
by: handle_one_connection (sql_connect.cc:1127)
by: start_thread (in /lib/libpthread-2.5.so)
by: clone (in /lib/libc-2.5.so)
 Address 0x65a5982 is 18 bytes inside a block of size 8,192 free'd
at: free (vg_replace_malloc.c:325)
by: end_io_cache (mf_iocache.c:1832)
by: MYSQL_LOG::close(unsigned int) (log.cc:2053)
by: MYSQL_BIN_LOG::close(unsigned int) (log.cc:4918)
by: MYSQL_BIN_LOG::new_file_impl(bool) (log.cc:3819)
by: MYSQL_BIN_LOG::rotate_and_purge (log.cc:3734)
by: reload_acl_and_cache (sql_parse.cc:6837)
by: mysql_execute_command(THD*) (sql_parse.cc:3973)
by: mysql_parse (sql_parse.cc:5961)
by: dispatch_command (sql_parse.cc:1233)
by: do_command(THD*) (sql_parse.cc:874)
by: handle_one_connection 
by: start_thread 
by: clone 

Debug binary has an unrelated debug assertion also during 'flush logs'.

How to repeat:
Put binlogs on another mount, then unmount and mount readonly while mysqld runs.
Create a mount, using procedure similar to this:

dd if=/dev/zero of=/tmp/loopback.img bs=1M count=10
/sbin/mkfs -t ext2 -v /tmp/loopback.img
mkdir -p /tmp/logs
mount -o loop /tmp/loopback.img /tmp/logs
chown mysql:mysql /tmp/loopback.img
chown mysql:mysql /tmp/logs

valgrind --tool=memcheck --track-origins=yes --leak-check=full -v  
--num-callers=50 ./bin/mysqld --no-defaults --skip-grant-tables 
--skip-name-resolve --basedir=. --datadir=./data  --log-bin=/tmp/logs/binlog

create table t1(a int);insert into t1 values (1);

#now make the binlogs readonly!

umount -d -l -f /tmp/logs
mount -r -o loop /tmp/loopback.img /tmp/logs

Next, trigger the binlog failure;

flush logs;
insert into t1 values (1);

#check the valgrind output

Suggested fix:
don't overrun memory!
[9 Feb 2010 9:27] MySQL Verification Team
uncut valgrind output from 5.1.43

Attachment: bug51019_full_valgrind_output_5.1.43.txt (text/plain), 70.08 KiB.

[9 Feb 2010 10:42] MySQL Verification Team
I guess you could see same error with disk full, wrong permissions, etc.
[9 Feb 2010 10:48] Valeriy Kravchuk
Thank you for the bug report. Verified with recent 5.1.45 from bzr on Linux.
[30 Mar 2010 8:50] Zhenxing He
I think this is a dup of bug#46166