MySQL Bugs: #37221: SET AUTOCOMMIT=1 does not commit binary log

Bug #37221	SET AUTOCOMMIT=1 does not commit binary log
Submitted:	5 Jun 2008 11:49	Modified:	27 Oct 20:13
Reporter:	Mats Kindahl
Status:	Closed
Category:	Server: Replication	Severity:	S2 (Serious)
Version:	6.0	OS:	Any
Assigned to:	Mats Kindahl	Target Version:	6.0-beta
Triage:	D2 (Serious) / R2 (Low) / E2 (Low)

Description:
When setting AUTOCOMMIT=1 there is an implicit commit executed. However, the binary log is
not committed correctly when using the Falcon storage engine.

According to the manual "[t]o disable autocommit mode for a single series of statements,
use the START TRANSACTION statement", meaning that inside an explicit transaction, it is
reasonable that autocommit is disabled regardless of the actual value of the AUTOCOMMIT
variable.

How to repeat:
CREATE TABLE t1 (a INT) ENGINE = Falcon;
SET AUTOCOMMIT=0
INSERT INTO t1 VALUES (1);
SET AUTOCOMMIT=1;
SHOW BINLOG EVENTS;
# See that there is no insert in the binary log

Suggested fix:
Move the implicit commit to be first in set_option_autocommit() since the binary log will
see the new option settings instead of the old option settings, causing it to not commit
an outstanding uncommitted transaction.

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/47468

ChangeSet@1.2687, 2008-06-05 11:57:19+02:00, mats@mats-laptop.(none) +6 -0
  Bug #37221: SET AUTOCOMMIT=1 does not commit binary log
  
  When setting AUTOCOMMIT=1 after starting a transaction, the binary log
  did not commit the outstanding transaction. The reason was that the binary
  log commit function saw the values of the new settings, deciding that there
  were nothing to commit.
  
  Fixed the problem by moving the implicit commit to before the thread option
  flags were changed, so that the binary log sees the old values of the flags
  instead of the values they will take after the statement.

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/47469

ChangeSet@1.2687, 2008-06-05 12:06:25+02:00, mats@mats-laptop.(none) +6 -0
  Bug #37221: SET AUTOCOMMIT=1 does not commit binary log
  
  When setting AUTOCOMMIT=1 after starting a transaction, the binary log
  did not commit the outstanding transaction. The reason was that the binary
  log commit function saw the values of the new settings, deciding that there
  were nothing to commit.
  
  Fixed the problem by moving the implicit commit to before the thread option
  flags were changed, so that the binary log sees the old values of the flags
  instead of the values they will take after the statement.

Related to showstopper bug

Related to showstopper bug#36745.

Manyi,

when setting the showstopper flag, IMO it is mandatory to also set the target version -
how else shall we know which build should wait until the patch is available ?

Patch approved pending correction of 3 minor items:

1) The original repository was bk mysql-6.0-rpl but the bzr tree is now being used. Patch
must be recommitted under a suitable bzr branch to work.

2) The test rpl_falcon_bug_36468 failed to execute when placed the folder specified in the
patch. I was able to get it to run by moving it to the rpl suite but...

3) The same test fails (content mismatch):

============================================================

TEST                            RESULT        TIME (ms)
------------------------------------------------------------

binlog.binlog_autocommit 'row' [ pass ]            164
Restarting all servers
binlog.binlog_autocommit 'stmt' [ pass ]             81
Restarting all servers
binlog.binlog_autocommit 'mix' [ pass ]             82
Restarting all servers
rpl.rpl_falcon_bug_36468 'row' [ pass ]            149

The check of testcase 'rpl.rpl_falcon_bug_36468' failed, this is the
 diff between before and after:

--- c:/source/bzr/mysql-6.0-bug-37221/mysql-test/var/tmp/check-mysqld.1.result20
08-06-06 19:55:00.267788200 +0300
+++ c:\source\bzr\mysql-6.0-bug-37221\mysql-test\var\tmp\check-mysqld.reject2008
-06-06 19:55:02.583788200 +0300
@@ -269,6 +269,7 @@
 NULL   mysql   latin1  latin1_swedish_ci       NULL
 NULL   test    latin1  latin1_swedish_ci       NULL
 tables_in_test
+t1
 tables_in_mysql
 mysql.columns_priv
 mysql.db

mysqltest: Result content mismatch

The check of testcase 'rpl.rpl_falcon_bug_36468' failed, this is the
 diff between before and after:

--- c:/source/bzr/mysql-6.0-bug-37221/mysql-test/var/tmp/check-mysqld.2.result20
08-06-06 19:55:00.726788200 +0300
+++ c:\source\bzr\mysql-6.0-bug-37221\mysql-test\var\tmp\check-mysqld.reject2008
-06-06 19:55:03.508788200 +0300
@@ -269,6 +269,7 @@
 NULL   mysql   latin1  latin1_swedish_ci       NULL
 NULL   test    latin1  latin1_swedish_ci       NULL
 tables_in_test
+t1
 tables_in_mysql
 mysql.columns_priv
 mysql.db

mysqltest: Result content mismatch

Stopping all servers...
Resuming tests...

Restarting all servers
rpl.rpl_falcon_bug_36468 'stmt' [ fail ]

CURRENT_TEST: rpl.rpl_falcon_bug_36468
mysqltest: At line 13: query 'INSERT INTO t1 VALUES (1)' failed: 1598: Binary lo
gging not possible. Message: Statement-based format required for this statement,
 but not allowed by this combination of engines

The result from queries just before the failure was:
stop slave;
drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
reset master;
reset slave;
drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
start slave;
[master]
SET GLOBAL BINLOG_FORMAT = 'ROW';
CREATE TABLE IF NOT EXISTS t1 (id INT) ENGINE = Falcon;
SET AUTOCOMMIT=0;
INSERT INTO t1 VALUES (1);

More results from queries before failure can be found in c:\source\bzr\mysql-6.0
-bug-37221\mysql-test\var\log\rpl_falcon_bug_36468.log

mysql-test-run: *** ERROR: Test 'rpl.rpl_falcon_bug_36468' failed. To continue,
re-run with '--force'
Autoreleasing /tmp/mysql-test-ports:200
Killing: [mysqld.2 - pid: 3652, winpid: 2144]
Killing: [mysqld.1 - pid: 960, winpid: 4368]
Killing: [timer - pid: 3956]

Test case rpl_falcon_bug_36468 passes if both fixes (36468 and 37221) are in place, and if
invoked with the following command line:

perl mysql-test-run.pl --mysqld=--skip-innodb --mysqld=--default-storage-engine=falcon
--suite=falcon rpl_falcon_bug_36468.test

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/47681

2696 Mats Kindahl	2008-06-10
      BUG#37221: SET AUTOCOMMIT=1 does not commit binary log
      
      Adding comment to Falcon regression test for the bug.

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/47683

2696 Mats Kindahl	2008-06-10
      BUG#37221: SET AUTOCOMMIT=1 does not commit binary log
      
      Adding comment to Falcon regression test for the bug.

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/47688

2697 Mats Kindahl	2008-06-10 [merge]
      Merging.

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/47777

ChangeSet@1.2627, 2008-06-12 13:36:39+02:00, jperkin@mysql.com +6 -0
  Merge -r2694..2696 from mysql-6.0-falcon bzr tree.  Original comments:
  ------------------------------------------------------------
  revno: 2696
  committer: Mats Kindahl <mats@mysql.com>
  branch nick: b37221-mysql-6.0-falcon
  timestamp: Tue 2008-06-10 14:39:13 +0200
  message:
    BUG#37221: SET AUTOCOMMIT=1 does not commit binary log
  
    Adding comment to Falcon regression test for the bug.
  ------------------------------------------------------------
  revno: 2695
  committer: Mats Kindahl <mats@mysql.com>
  branch nick: b37221-mysql-6.0-falcon
  timestamp: Mon 2008-06-09 21:32:42 +0200
  message:
    Bug #37221: SET AUTOCOMMIT=1 does not commit binary log
  
    When setting AUTOCOMMIT=1 after starting a transaction, the binary log
    did not commit the outstanding transaction. The reason was that the binary
    log commit function saw the values of the new settings, deciding that there
    were nothing to commit.
  
    Fixed the problem by moving the implicit commit to before the thread option
    flags were changed, so that the binary log sees the old values of the flags
    instead of the values they will take after the statement.

Pushed into 6.0.7-alpha  (revid:serg@mysql.com-20080722121106-wy84j0yvceyu72zr) (pib:2)

Documented bugfix in the 6.0.7 changelog as follows:

        When setting AUTOCOMMIT=1 after starting a transaction, the binary log
        did not commit the outstanding transaction. The reason this happened was 
        that the binary log commit function saw only the values of the new 
        settings, and decided that there was nothing to commit.

        This issue was observed when using the Falcon storage engine, but it is 
        possible that it affected other storage engines as well.

Pushed into 6.0.7-alpha 
(revid:sp1r-jperkin/mysqldev@mysql.com/production.mysql.com-20080612113639-04418) (version
source revid:john.embretsen@sun.com-20080724122511-9c0oudz1xrdrs6y6) (pib:3)

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/84328

3108 Mats Kindahl	2009-09-23
      Bug #37221: SET AUTOCOMMIT=1 does not commit binary log
      
      When setting AUTOCOMMIT=1 after starting a transaction, the binary log
      did not commit the outstanding transaction. The reason was that the binary
      log commit function saw the values of the new settings, deciding that there
      were nothing to commit.
      
      Fixed the problem by moving the implicit commit to before the thread option
      flags were changed, so that the binary log sees the old values of the flags
      instead of the values they will take after the statement.
     @ mysql-test/extra/binlog_tests/implicit.test
        New test file to check implicit commits both inside and outside transactions.
     @ mysql-test/suite/binlog/t/binlog_implicit_commit.test
        Test for implicit commit of SET AUTOCOMMIT and LOCK/UNLOCK TABLES.
     @ sql/set_var.cc
        Adding code to commit pending transaction before changing option flags.

Pushed into 6.0.14-alpha (revid:alik@sun.com-20091027094604-9p7kplu1vd2cvcju) (version
source revid:zhenxing.he@sun.com-20091026140226-uhnqejkyqx1aeilc) (merge vers:
6.0.14-alpha) (pib:13)

Already documented for 6.0.7.

Closed.