Bug #40276 Assertion trx_data->empty() in binlog_close_connection
Submitted: 23 Oct 2008 8:31 Modified: 17 Sep 2012 14:50
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Row Based Replication ( RBR ) Severity:S1 (Critical)
Version:5.1-rpl, 5.1-bzr OS:Any
Assigned to: Mats Kindahl CPU Architecture:Any

[23 Oct 2008 8:31] Philip Stoev
Description:
When executing a non-concurrent workload containing various transactional statements:

        START TRANSACTION | COMMIT | ROLLBACK |
        SAVEPOINT A | ROLLBACK TO SAVEPOINT A | RELEASE SAVEPOINT A |
        SET AUTOCOMMIT = ON | SET AUTOCOMMIT = OFF ;

the server asserts as follows:

#8  0x003df57e in __assert_fail () from /lib/libc.so.6
#9  0x08356a99 in binlog_close_connection (hton=0x92b6330, thd=0x97ecd58) at log.cc:1337
#10 0x083b9acc in closecon_handlerton (thd=0x97ecd58, plugin=0xb2a5028c, unused=0x0) at handler.cc:559
#11 0x08467dc6 in plugin_foreach_with_mask (thd=0x97ecd58, func=0x83b9a6b <closecon_handlerton>, type=1, state_mask=4294967287, arg=0x0)
    at sql_plugin.cc:1814
#12 0x083b619f in ha_close_connection (thd=0x97ecd58) at handler.cc:570
#13 0x08276b1b in ~THD (this=0x97ecd58) at sql_class.cc:892
#14 0x0828c2dd in unlink_thd (thd=0x97ecd58) at mysqld.cc:1803
#15 0x0828c34f in one_thread_per_connection_end (thd=0x97ecd58, put_in_cache=true) at mysqld.cc:1882
#16 0x08295238 in handle_one_connection (arg=0x97ecd58) at sql_connect.cc:1122
#17 0x0057d32f in start_thread () from /lib/libpthread.so.0
#18 0x0049a27e in clone () from /lib/libc.so.6

(gdb) frame 9
#9  0x08356a99 in binlog_close_connection (hton=0x92b6330, thd=0x97ecd58) at log.cc:1337
1337      DBUG_ASSERT(trx_data->empty());

How to repeat:
A test case will be uploaded shortly.
[23 Oct 2008 8:33] Philip Stoev
YY file

Attachment: bug40276.yy (application/octet-stream, text), 514 bytes.

[23 Oct 2008 8:36] Philip Stoev
To reproduce with the random query generator, please clone the mysql-test-extra-6.0 tree and then issue:

$ cd mysql-test-extra-6.0/mysql-test/gentest
$ perl runall.pl \
  --basedir=/path/to/mysql-5.1 \
  --grammar=bug40276.yy \
  --rpl_mode=row \
  --queries=2000 \
  --threads=1
[23 Oct 2008 15:18] Valeriy Kravchuk
Verified just as described with latest debug build of 5.1 main tree from bzr.
[30 Oct 2008 18:24] Valeriy Kravchuk
With --rpl_mode=statement there is no assertion.
[15 Dec 2008 20:58] Mats Kindahl
It is not possible to repeat the bug. This bug is probably fixed as one of the other bugs reported in this batch of bugs triggered by the random query generator.
[2 Nov 2010 14:35] Sven Sandberg
I can repeat this in 5.1-bugteam on a full disk. This uses a script to mount a small filesystem on mysql-test/var:

$ ./mtr-limit-vardir 5620000

$ ./mtr rpl_bug40276
[...]
mysqld: log.cc:1376: int binlog_close_connection(handlerton*, THD*): Assertion `trx_data->empty()' failed.
[...]

==== BEGIN mtr-limit-vardir ====
#!/usr/bin/perl -w
# This script limits the vardir of a mysql source tree to
# a given number of bytes.
use strict;
use warnings;
# Get size
die "Usage: $0 SIZE" if @ARGV != 1;
my $size = shift;
die "Usage: $0 SIZE" if $size !~ /^[0-9]+$/;
# Get and check paths
my $root = `bzr root`;
chomp($root);
$root .= '/mysql-test';
die "$root not found" if !-d $root;
die "$root/var not found" if !-d "$root/var";
my $image = "$root/var_fs_file";
my $var = "$root/var";
# Unmount old vardir
my $mounted = `mount | grep -w '$var'`;
if ($mounted) {
  print "Unmounting $var\n";
  system("sudo umount '$var'") == 0
    or die "Error running umount '$var': $!";
}
else {
  print "Renaming $var to $var.backup\n";
  rename("$var", "$var.backup")
    or die "failed to rename $var to $var.backup: $!";
  mkdir("$var")
    or die "failed to create $var: $!";
}
# Create image
system("head -c '$size' /dev/zero > '$image'") == 0
  or die "Error running head > '$image': $!";
system("mkfs.ext2 -F '$image'") == 0
  or die "Error running mkfs.ext2 -F '$image': $!";
system("sudo mount -o loop '$image' '$var'") == 0
  or die "Error running sudo mount '$image' '$var': $!";
==== END mtr-limit-vardir ====

==== BEGIN rpl_bug40276.test ====
--source include/master-slave.inc
--source include/have_binlog_format_row.inc
--disable_query_log
SET GLOBAL GENERAL_LOG = OFF;
--let $long_string= `SELECT REPEAT('a', 500000)`
--let $f= $MYSQLTEST_VARDIR/tmp/bigfile
--eval SELECT '$long_string$long_string' INTO DUMPFILE '$f.1'
--eval SELECT '$long_string$long_string' INTO DUMPFILE '$f.2'
--echo # create table
CREATE TABLE t1 (a TEXT(1000000));
--echo # execute big statement
--eval INSERT INTO t1 VALUES ('$long_string');
DROP TABLE t1;
SET GLOBAL GENERAL_LOG = ON;
--enable_query_log
--sync_slave_with_master
==== END rpl_bug40276.test ====
[17 Sep 2012 14:50] Jon Stephens
Thank you for your bug report. This issue has been committed to our source repository of that product and will be incorporated into the next release.

If necessary, you can access the source repository and build the latest available version, including the bug fix. More information about accessing the source trees is available at

    http://dev.mysql.com/doc/en/installing-source.html
[17 Sep 2012 14:50] Jon Stephens
Fixed in 5.1.67, 5.5.29, 5.6.8. Closed.