MySQL Bugs: #57441: backup of data after reported binlog pos when using non-tx table in transaction

Bug #57441	backup of data after reported binlog pos when using non-tx table in transaction
Submitted:	13 Oct 2010 17:47	Modified:	20 Mar 2012 2:53
Reporter:	Victor Kirkebo	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Enterprise Backup	Severity:	S3 (Non-critical)
Version:	3.5	OS:	Any
Assigned to:	Thava Alagu	CPU Architecture:	Any

Description:
When using a non-transactional table (e.g. MyISAM) together with a transactional table (e.g. InnoDB) inside a transaction changes to the non-transactional table are written to the table before the commit while the changes to the transactional table are written only after commit (which could be much later). However, in the binlog the changes to the non-transactional table and the transactional table are both logged with the binlog position that corresponds to the commit.

When taking a backup this might result in a backup containing data from a non-transactional table that have a binlog position that comes after the binlog position that mysqlbackup reports having backed up.

This is more likely to happen if, in the transaction, there is a "long" time delay between the changes made to the non-transactional table and the time that commit is called.

How to repeat:
Call the code given below from a client. Note that there is a 60 sec delay between the insert and the commit. Run a backup that finishes before those 60 secs have expired. When starting a database based on that backup you should be able to verify that the database contains 1 row in the MyISAM table "log" and 0 rows in the InnoDB table "t1". mysqlbackup also reported a binlog position when the backup was completed. Open the binlog and go to that binlog position. Verify that the row inserted into the MyISAM table appears AFTER that binlog position.

create database tst;
use tst;

create table t1(id INT NOT NULL AUTO_INCREMENT, PRIMARY KEY (id), f1 varchar(10) ) engine=InnoDB;
create table log(id INT) engine=MyISAM;

delimiter //;
create trigger ins_trg after insert on t1 for each row
begin
  insert into log(id) values(new.id);
end//
delimiter ;//

set autocommit=0;
insert into t1(f1) values("ABC");
select sleep(60);
commit;

Thank you for the report.

When trying to run test from source directory I get error:

Trying to set up a reference system with port=10750
=======================================================================
Could not find MySQL daemon client: '/users/ssmirnova/blade12/src/mysql-5.1-meb/libexec/mysqld'

What should I fix to avoid this?

Thank you for the feedback.

You were right: files were not copied. Verified as described.

I did additional modification to test file: added

echo socket=/tmp/10760.sock >> $TST_PATH/backup/backup-my.cnf

at line 81, so it can run while I have another mysqld using /tmp/mysql.sock

The real problem is not that backup reports "old" binlog position. The problem is that we take the snapshot of MYISAM tables at binlog position "X", but it has physical changes caused by uncommitted triggers. When you rollback the trigger statement later, the changes to non-transactional tables are not rolled back. This is just the way triggers are implemented.

I don't think the problem is critical for MySQL backup. There is no inconsistencies in innodb tables which is what it is primarily meant for.
However we do have a problem by declaring the backup corresponds to binlog position X where some MyISAM tables may contain extraneous updates caused by some uncommitted trigger statements. It is important to note that the problem is restricted to "uncommitted trigger" statements only-- not any uncommitted statements. I think this should be documented, but not sure if it is important enough to fix it as there is no easy way to fix this for backup and consistency of MyISAM tables is not our focus.

It is interesting to note that this is not specifically a problem for replication. Anyway, the binlog behaviour was much influenced by replication implementation to make sure the inability to completely rollback triggers won't break replication at slaves.

The root cause of the problem is that the way triggers are implemented. Rolling back trigger statements does not rollback updates in non-transactional tables. It issues warning messages when such rollbacks are done.

Just a modified SQL statements from Victor's test case illustrates the behaviour of trigger statements wrt how binlog grows:

mysql> 
mysql> drop database if exists tst;
Query OK, 0 rows affected, 1 warning (0.01 sec)

mysql> create database tst;
Query OK, 1 row affected (0.05 sec)

mysql> use tst;
Database changed
mysql> 
mysql> create table t1(id INT NOT NULL AUTO_INCREMENT, PRIMARY KEY (id), f1 varchar(10) ) engine=InnoDB;
Query OK, 0 rows affected (0.03 sec)

mysql> create table log(id INT) engine=MyISAM;
Query OK, 0 rows affected (0.01 sec)

mysql> 
mysql> delimiter //
mysql> 
mysql> create trigger ins_trg after insert on t1 for each row
    -> begin
    ->   insert into log(id) values(new.id);
    -> end//
Query OK, 0 rows affected (0.01 sec)

mysql> 
mysql> delimiter ;
mysql> 
mysql> set autocommit=0;
Query OK, 0 rows affected (0.00 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| mysql-bin.000001 |      741 |              |                  |
+------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

mysql> insert into t1(f1) values("step1");
Query OK, 1 row affected (0.01 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| mysql-bin.000001 |      741 |              |                  |
+------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

mysql> select * from log;
+------+
| id   |
+------+
|    1 |
+------+
1 row in set (0.00 sec)

mysql> rollback;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| mysql-bin.000001 |     1002 |              |                  |
+------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

mysql> show warnings;
+---------+------+---------------------------------------------------------------+
| Level   | Code | Message                                                       |
+---------+------+---------------------------------------------------------------+
| Warning | 1196 | Some non-transactional changed tables couldn't be rolled back |
+---------+------+---------------------------------------------------------------+
1 row in set (0.00 sec)

mysql> select * from log;
+------+
| id   |
+------+
|    1 |
+------+
1 row in set (0.00 sec)

mysql> insert into t1(f1) values("step2");
Query OK, 1 row affected (0.00 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| mysql-bin.000001 |     1002 |              |                  |
+------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

mysql> select * from log;
+------+
| id   |
+------+
|    1 |
|    2 |
+------+
2 rows in set (0.00 sec)

mysql> commit;
Query OK, 0 rows affected (0.01 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| mysql-bin.000001 |     1220 |              |                  |
+------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

mysql> select * from log;
+------+
| id   |
+------+
|    1 |
|    2 |
+------+
2 rows in set (0.00 sec)

mysql>

This has to be documented as a limitation of Point-In-Time recovery capability of the backup. It can be worded something like below:
   Under certain conditions, the physical backup taken by MyISAM may contain some extraneous updates which is not exactly in sync with the binlog position that the backup records. This can happen if following condtions are met during backup:  (1) there are open transactions involving transactional and transactional tables and (2) the triggers which are fired on updates to transactional tables causes updates to non-transactional tables and (3) statement based bin logging is in effect.

Actually the conditions just described are not the only conditions because the problem is not specific to triggers and not specific to binlog format either. It occurs when update statements mix transactional and non-transactional tables and autocommit is disabled. Consider the following:

set autocommit=0;
create table isam(i int) engine=MyISAM;
create table ib(i int) engine=InnoDB;
insert into isam values(1);
insert into ib values(2);

begin;
show master status;         ==> Say, binlog pos X
insert into isam select * from ib;
insert into isam select * from ib;
show master status;         ==> The binlog pos reported is still X;
                                But MyISAM physical table gets updated.

select sleep(60);        ==> Backup taken now contains extra 2 updates in
                             isam table, but associates with old binlog pos
                             at the start of transaction.
commit;
show master status;

The above behaviour is same for all binlog formats: row, statement and mixed.
There is no easy way to fix this for backup and hence we need to accept this limitations in supporting PTR - point-in-time recovery and document it accordingly.

Hence more refined statement of limitation would be:

  While the binlog position of the backup taken is accurate with respect to transactional tables, it may not be accurate for non-transactional tables under following conditions while taking backup:
   (1)  There are open transactions with autocommit turned off  AND
   (2)  The transactions involve both transactional and non-transactional tables. In such cases, the binlog position is not updated until the transaction commits. In the meantime, the physical updates to MyISAM table happens without updating binlog position. As a result, the backup taken may contain extraneous updates in MyISAM tables which correspond to the real updates that would have taken place after the reported binlog position by backup.

Added under "Known Bugs and Limitations":

In some cases, backups of non-transactional tables such as MyISAM 
tables could contain additional uncommitted data. If autocommit is 
turned off, and both InnoDB tables and non-transactional tables are 
modified within the same transaction, data can be written to the 
non-transactional table before the binlog position is updated. The 
binlog position is updated when the transaction is committed, but the 
non-transactional data is written immediately. If the backup occurs 
while such a transaction is open, the backup data contains the 
updates made to the non-transactional table.