Bug #51251 Wrong binlogging in case of TRUNCATE <temporary InnoDB table>
Submitted: 17 Feb 2010 18:46 Modified: 21 Jun 2010 0:55
Reporter: Matthias Leich Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:5.1.45,5.5.99-m3 OS:Any
Assigned to: Luis Soares CPU Architecture:Any

[17 Feb 2010 18:46] Matthias Leich
Description:
My script:
----------
--source include/master-slave.inc
--source include/have_innodb.inc

SET SESSION BINLOG_FORMAT = ROW;
CREATE TABLE `t1` ( pk int , primary key (pk)) ENGINE=InnoDB;
CREATE TEMPORARY TABLE IF NOT EXISTS  t2 LIKE t1;
TRUNCATE TABLE test . t2;

--connection master
--sync_slave_with_master

Result on 5.1.45
mysql-5.1-bugteam revno: 3345 2010-02-17
----------------------------------------
./mysql-test-run.pl --mysqld=--binlog-format=row --record --no-check-testcases --skip-ndbcluster --mem  t/rpl_ml15.test
...
main.rpl_ml15                            [ fail ]
...
=== SHOW SLAVE STATUS ===
---- 1. ----
...
Last_Errno      1146
Last_Error      Error 'Table 'test.t2' doesn't exist' on query. Default database: 'test'. Query: 'TRUNCATE TABLE test . t2'

This is not surprising because the binary log is incomplete.

SHOW BINLOG EVENTS IN 'master-bin.000001';
Log_name        Pos     Event_type      Server_id       End_log_pos     Info
master-bin.000001       4       Format_desc     1       106     Server ver: 5.1.45-debug-log, Binlog ver: 4
master-bin.000001       106     Query   1       229     use `test`; CREATE TABLE `t1` ( pk int , primary key (pk)) ENGINE=InnoDB
master-bin.000001       229     Query   1       316     use `test`; TRUNCATE TABLE test . t2
   <== Truncating a temporary table where the
       the "CREATE TEMPORARY TABLE .." is already
       missing cannot work.

The problem disappears if I
- use MyISAM instead of InnoDB
or
- use SESSION BINLOG_FORMAT = STATEMENT or ROW
or
- let t2 be a non temporary table

We have the same problem in
5.5.99-m3
mysql-next revno: 3101 2010-02-16

There are several bugs for replication, TRUNCATE and
InnoDB but none of them seems to match my scenario.

How to repeat:
See above
./mysql-test-run.pl --mysqld=--binlog-format=row --record --no-check-testcases --skip-ndbcluster t/rpl_ml15.test
[19 Feb 2010 0:00] Luis Soares
See also: BUG#48350.
[19 Feb 2010 0:22] 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/100817

3341 Luis Soares	2010-02-19
      BUG#51251: Wrong binlogging in case of TRUNCATE <temporary InnoDB table>
      
      For temporary tables that are created with an engine that does
      not provide the HTON_CAN_RECREATE, the truncate operation is
      performed resorting to the optimized handler::ha_delete_all_rows
      method. However, this means that the truncate will share
      execution path, from mysql_delete, with truncate on regular
      tables and other delete operations. As a consequence the truncate
      operation, for the temporary table is logged, even if in row mode
      because there is no distinction between this and the other delete
      operations at binlogging time.
      
      We fix this by checking if: (i) the binlog format, when the
      truncate operation was issued, is ROW; (ii) if the operation is a
      truncate; and (iii) if the table is a temporary table; before
      writing to the binary log. If all three conditions are met, we
      skip writing to the binlog.
     @ mysql-test/suite/binlog/r/binlog_row_mix_innodb_myisam.result
        Updated result for spurious truncate table.
     @ mysql-test/suite/binlog/t/binlog_row_innodb_truncate.test
        Test case.
     @ sql/mysql_priv.h
        Added parameter in mysql_delete interface.
     @ sql/sql_delete.cc
        Added check in mysql_delete before writing the TRUNCATE statement
        to the binary log.
     @ sql/sql_parse.cc
        Added value for the new parameter in mysql_delete.
[24 Feb 2010 19:02] 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/101369

3341 Luis Soares	2010-02-24
      BUG#51251: Wrong binlogging in case of TRUNCATE <temporary InnoDB table>
      
      For temporary tables that are created with an engine that does
      not provide the HTON_CAN_RECREATE, the truncate operation is
      performed resorting to the optimized handler::ha_delete_all_rows
      method. However, this means that the truncate will share
      execution path, from mysql_delete, with truncate on regular
      tables and other delete operations. As a consequence the truncate
      operation, for the temporary table is logged, even if in row mode
      because there is no distinction between this and the other delete
      operations at binlogging time.
      
      We fix this by checking if: (i) the binlog format, when the
      truncate operation was issued, is ROW; (ii) if the operation is a
      truncate; and (iii) if the table is a temporary table; before
      writing to the binary log. If all three conditions are met, we
      skip writing to the binlog. A side effect of this fix is that we
      limit the scope of setting and resetting the
      current_stmt_binlog_row_based. Now we just set and reset it
      inside mysql_delete in the boundaries of the
      handler::ha_write_row loop. This way we have access to
      thd->current_stmt_binlog_row_based real value inside
      mysql_delete.
     @ mysql-test/suite/binlog/r/binlog_row_mix_innodb_myisam.result
        Updated result for spurious truncate table.
     @ mysql-test/suite/binlog/t/binlog_row_innodb_truncate.test
        Test case.
     @ sql/sql_delete.cc
        Added check in mysql_delete before writing the TRUNCATE statement
        to the binary log. Additionally, removed the set/reset of
        current_stmt_binlog_row_based so that it happens just in the 
        boundaries of the handler::ha_write_row loop inside mysql_delete.
[26 Feb 2010 12: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/101634

3342 Luis Soares	2010-02-26
      BUG#51251: Wrong binlogging in case of TRUNCATE <temporary InnoDB table>
      
      Incremental commit based on previous patch.
      Addresses reviewer comments to move reseting of 
      thd->current_stmt_binlog_row_based to after binlog_query
      takes place.
[9 Mar 2010 23:41] 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/102797

3384 Luis Soares	2010-03-09
      Post-push fix for BUG#51251.
      
      The test case added in previous patch missed a RESET MASTER on
      test start up. Without it, showing binary log contents can
      sometimes show spurious entries from previously executed tests,
      ultimately causing test failure - result mismatch.
      
      The test file was added in:
      revid:luis.soares@sun.com-20100224190153-k0bpdx9abe88uoo2
      
      This patch also moves the test case into binlog_innodb_row.test
      file. This way we avoid having yet another test file,
      binlog_row_innodb_truncate.test, whose only purpose is to host
      one test case. This had been actually suggested during original
      patch review, but somehow the binlog_innodb_row was missed when
      searching for a file to host the test case.
[26 Mar 2010 8:23] Bugs System
Pushed into 5.5.4-m3 (revid:alik@sun.com-20100326080914-2pz8ns984e0spu03) (version source revid:alexey.kopytov@sun.com-20100312095153-t4rtoqc7p96lmxvh) (merge vers: 5.5.3-m2) (pib:16)
[26 Mar 2010 8:27] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100326081116-m3v4l34yhr43mtsv) (version source revid:alik@sun.com-20100325072612-4sds00ix8ajo1e84) (pib:16)
[26 Mar 2010 8:29] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100326081944-qja07qklw1p2w7jb) (version source revid:alik@sun.com-20100325073410-4t4i9gu2u1pge7xb) (merge vers: 6.0.14-alpha) (pib:16)
[29 Mar 2010 14:48] Jon Stephens
Documented bugfix in the 5.5.4 and 6.0.14 changelogs as follows:

      TRUNCATE performed on a temporary table using the InnoDB 
      storage engine was logged even when using row-based mode.

NM - waiting on 5.1.
[31 Mar 2010 16:03] Paul DuBois
5.5.4 changelog entry was moved to 5.5.5.
[6 Apr 2010 8:01] Bugs System
Pushed into 5.1.46 (revid:sergey.glukhov@sun.com-20100405111026-7kz1p8qlzglqgfmu) (version source revid:luis.soares@sun.com-20100310000733-ap46g3c0k86wtnw1) (merge vers: 5.1.45) (pib:16)
[6 Apr 2010 11:34] Jon Stephens
Also documented bugfix in the 5.1.46 changelog; closed.
[17 Jun 2010 11:59] Bugs System
Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 12:38] Bugs System
Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:martin.skold@mysql.com-20100609211156-tsac5qhw951miwtt) (merge vers: 5.1.46-ndb-6.2.19) (pib:16)
[17 Jun 2010 13:24] Bugs System
Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)