Bug #23333 stored function + non-transac table + transac table = breaks stmt-based binlog
Submitted: 16 Oct 2006 13:23 Modified: 16 Sep 2008 19:05
Reporter: Guilhem Bichot Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:5.1-bk, 5.0 BK OS:Linux (linux)
Assigned to: Andrei Elkin

[16 Oct 2006 13:23] Guilhem Bichot
Description:
**** I did NOT test 5.0; Verifier, please test it ****

This is a problem similar to the one of BUG#12713, applied to mixed and statement-based replication.
mysql_update() has:
  if ((error < 0) || (updated && !transactional_table))
  {
    if (mysql_bin_log.is_open())
    {
      if (error < 0)
        thd->clear_error();
      if (thd->binlog_query(THD::ROW_QUERY_TYPE,
                            thd->query, thd->query_length,
                            transactional_table, FALSE) &&
          transactional_table)
      {
	error=1;				// Rollback update
      }
    }
In my testcase, the table in UPDATE is transactional, there is an error, so the if() condition is false and nothing is written to the binlog. But as a side-effect of the UPDATE, a non-transactional table is updated, so the binlog is out of sync.
Row-based binlogging does not have this problem apparently (my testcase does not produce bad results there).

How to repeat:
source include/master-slave.inc;

create table t1(a int, unique(a)) engine=innodb;
create table t2(a int) engine=myisam;
drop function if exists fn1;

delimiter |;
create function fn()
       returns int
begin
  insert into t2 values(100);
  return 1;
end|

delimiter ;|

insert into t1 values(1),(2);

--error 1062
UPDATE t1 SET a=fn() WHERE a=2;

select * from t1;
select * from t2;
sync_slave_with_master;
select * from t1;
select * from t2;

connection master;
show binlog events;
drop table t1,t2;
drop function fn;
sync_slave_with_master;

Results:
*** 0 ****
--- 1,50 ----
+ 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;
+ create table t1(a int, unique(a)) engine=innodb;
+ Warnings:
+ Warning       1266    Using storage engine MyISAM for table 't1'
+ create table t2(a int) engine=myisam;
+ drop function if exists fn1;
+ Warnings:
+ Note  1305    FUNCTION fn1 does not exist
+ create function fn()
+ returns int
+ begin
+ insert into t2 values(100);
+ return 1;
+ end|
+ insert into t1 values(1),(2);
+ UPDATE t1 SET a=fn() WHERE a=2;
+ ERROR 23000: Duplicate entry '1' for key 'a'
+ select * from t1;
+ a
+ 1
+ 2
+ select * from t2;
+ a
+ 100
+ select * from t1;
+ a
+ 1
+ 2
+ select * from t2;
+ a
+ show binlog events;
+ Log_name      Pos     Event_type      Server_id       End_log_pos     Info
+ master-bin.000001     4       Format_desc     1       102     Server ver: 5.1.13-beta-valgrind-max-debug-log, Binlog ver: 4
+ master-bin.000001     102     Query   1       212     use `test`; create table t1(a int, unique(a)) engine=innodb
+ master-bin.000001     212     Query   1       311     use `test`; create table t2(a int) engine=myisam
+ master-bin.000001     311     Query   1       481     use `test`; CREATE DEFINER=`root`@`localhost` function fn()
+ returns int
+ begin
+ insert into t2 values(100);
+ return 1;
+ end
+ master-bin.000001     481     Query   1       572     use `test`; insert into t1 values(1),(2)
+ drop table t1,t2;
+ drop function fn;

See: t2 is non-empty on master but is empty on slave.

Suggested fix:
Quite a convoluted example, but better know it than not.
[20 Oct 2006 20:43] Sveta Smirnova
Thank you for the report.

Verified as described on Linux using last 5.0 and 5.1 BK sources.
[20 Dec 2006 18:50] Andrei Elkin
Bug #13270 INSERT,UPDATE,etc that calls func with side-effect
relates closely.
[23 Mar 2007 19:56] 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/22831

ChangeSet@1.2491, 2007-03-23 21:54:11+02:00, aelkin@andrepl.(none) +7 -0
  Bug #23333  	stored function + non-transac table + transac table = breaks stmt-based binlog
  Bug #13270  	INSERT,UPDATE,etc that calls func with side-effect does not go into binlog
  
  The query was not binlogged if top-level table was transactional or unmodified while
  implicitly involved via stored function  non-ta table was modified.
  
  Fixed with checking thd->no_trans_update.all flag (refactored after thd->options' 
  OPTION_STATUS_NO_TRANS_UPDATE eliminated in
  Bug#27395 OPTION_STATUS_NO_TRANS_UPDATE is not preserved at the end of SF)
  at binlog recording time, and regardless of whether top level table got modified or not the query
  gets binlogged if the flag was set.
[16 May 2007 18:40] Sergei Golubchik
bug#13270 was marked as a duplicate of this bug, as one patch will fix them both.
Don't forget to open bug#13270 again, if, for some reason, it'll need a separate patch.
[15 Jun 2007 10:59] 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/28857

ChangeSet@1.2440, 2007-06-15 13:59:18+03:00, aelkin@dsl-hkibras1-ff5dc300-70.dhcp.inet.fi +8 -0
  Bug #23333 stored function + non-transac table + transac table = breaks stmt-based binlog
  
  Binlogging of the statement with a side effect like a modified non-trans table did not happen.
  The artifact involved all binloggable dml queries.
  
  Fixed with changing the binlogging conditions all over the code to exploit thd->no_trans_update.top introduced
  by the patch for bug#27417.
  
  Multi-delete case has own specific addressed by another bug_29136. Multi-update case has been addressed by bug#27716 and
  patch and will need merging.
[21 Jun 2007 20:11] Bugs System
Pushed into 5.0.46
[21 Jun 2007 20:14] Bugs System
Pushed into 5.1.20-beta
[22 Jun 2007 15:07] Andrei Elkin
It's not yet pushed. Until got reviewed. There is a bug in pushbuild script that generates list of bug of a push differently than post-commit: all the bug ids found in cset commets considered to be the targets of the pushed cset. That wrong decision was corrected only for post-commit script.
[26 Jun 2007 17:29] 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/29627

ChangeSet@1.2440, 2007-06-26 20:24:14+03:00, aelkin@dsl-hkibras1-ff5dc300-70.dhcp.inet.fi +8 -0
  Bug #23333 stored function + non-transac table + transac table = breaks stmt-based binlog
  
  Binlogging of the statement with a side effect like a modified non-trans table did not happen.
  The artifact involved all binloggable dml queries.
  
  Fixed with changing the binlogging conditions all over the code to exploit thd->transaction.stmt.modified_non_trans_table
[20 Aug 2007 17:03] 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/32764

ChangeSet@1.2440, 2007-08-20 20:02:52+03:00, aelkin@dsl-hkibras-fe38f900-157.dhcp.inet.fi +6 -0
  Bug #23333 stored function + non-transac table + transac table = breaks stmt-based binlog
  
  Binlogging of the statement with a side effect like a modified non-trans table did not happen.
  The artifact involved all binloggable dml queries.
  
  Fixed with changing the binlogging conditions all over the code to exploit thd->transaction.stmt.modified_non_trans_table
[21 Aug 2007 12:17] 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/32808

ChangeSet@1.2496, 2007-08-21 15:16:55+03:00, aelkin@dsl-hkibras-fe38f900-157.dhcp.inet.fi +8 -0
  Bug #23333 stored function + non-transac table + transac table = breaks stmt-based binlog
  
  Binlogging of the statement with a side effect like a modified non-trans table did not happen.
  The artifact involved all binloggable dml queries.
  
  Fixed with changing the binlogging conditions all over the code to exploit thd->transaction.stmt.modified_non_trans_table
[22 Aug 2007 12:43] 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/32869

ChangeSet@1.2498, 2007-08-22 15:43:16+03:00, aelkin@dsl-hkibras-fe38f900-157.dhcp.inet.fi +2 -0
  bug#23333
  
  fixing the test due a to different offsets in binlog with ps-protocol (a possible bug to be reported)
[27 Nov 2007 10:48] Bugs System
Pushed into 5.0.54
[27 Nov 2007 10:49] Bugs System
Pushed into 5.1.23-rc
[27 Nov 2007 10:52] Bugs System
Pushed into 6.0.4-alpha
[28 Nov 2007 18:58] 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

Documented bugfix in the 5.0.54, 5.1.23, and 6.0.4 changelogs as follows:
        
        An UPDATE statement using a stored function that modified a 
        non-transactional table was not logged if it failed. This caused the 
        copy of the non-transactional table on the master to have a row that 
        the copy on the slave did not.
[16 Sep 2008 15:36] Todd Farmer
I suspect the fix for this bug also fixed the following behavior, and that the documentation should be updated to clarify this fact.

When an INSERT ... ON DUPLICATE KEY UPDATE statement hits a duplicate key constraint, but the UPDATE does not actually change any data, the statement isn't written to the binary logs in 5.0.52:

mysql> USE test
Database changed
mysql> DROP TABLE IF EXISTS t1;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> CREATE TABLE t1 (a INT PRIMARY KEY, b INT, ts TIMESTAMP);
Query OK, 0 rows affected (0.02 sec)

mysql> INSERT INTO t1 (a, b) VALUES (1, 1), (2, 2), (3, 3);
Query OK, 3 rows affected (0.00 sec)
Records: 3  Duplicates: 0  Warnings: 0

mysql> SHOW MASTER STATUS\G
*************************** 1. row ***************************
            File: US-TF221715-02-bin.000001
        Position: 417
    Binlog_Do_DB:
Binlog_Ignore_DB:
1 row in set (0.00 sec)

mysql> INSERT INTO t1 (a, b) VALUES (1, 1) ON DUPLICATE KEY UPDATE a = 1, b = 1;

Query OK, 0 rows affected (0.00 sec)

mysql> SHOW MASTER STATUS\G
*************************** 1. row ***************************
            File: US-TF221715-02-bin.000001
        Position: 417
    Binlog_Do_DB:
Binlog_Ignore_DB:
1 row in set (0.00 sec)

mysql> select version();
+------------------------------+
| version()                    |
+------------------------------+
| 5.0.52-enterprise-gpl-nt-log |
+------------------------------+
1 row in set (0.02 sec)

However, it is written to the binary logs (correctly, IMHO, and consistent with handling of straight UPDATE statements) in 5.0.54:

mysql> DROP TABLE IF EXISTS t1;
Query OK, 0 rows affected (0.00 sec)

mysql> CREATE TABLE t1 (a INT PRIMARY KEY, b INT, ts TIMESTAMP);
Query OK, 0 rows affected (0.00 sec)

mysql> INSERT INTO t1 (a, b) VALUES (1, 1), (2, 2), (3, 3);
Query OK, 3 rows affected (0.00 sec)
Records: 3  Duplicates: 0  Warnings: 0

mysql> SHOW MASTER STATUS\G
*************************** 1. row ***************************
            File: US-TF221715-02-bin.000001
        Position: 1700
    Binlog_Do_DB:
Binlog_Ignore_DB:
1 row in set (0.00 sec)

mysql> INSERT INTO t1 (a, b) VALUES (1, 1) ON DUPLICATE KEY UPDATE a = 1, b = 1;

Query OK, 0 rows affected (0.00 sec)

mysql> SHOW MASTER STATUS\G
*************************** 1. row ***************************
            File: US-TF221715-02-bin.000001
        Position: 1835
    Binlog_Do_DB:
Binlog_Ignore_DB:
1 row in set (0.00 sec)
[16 Sep 2008 19:05] Jon Stephens
Thank you for your bug report. This issue has been addressed in the documentation. The updated documentation will appear on our website shortly, and will be included in the next release of the relevant products.

Changeset: http://lists.mysql.com/commits/54229