Bug #333 3 binlogging bugs when doing INSERT with mixed InnoDB / MyISAM

Description:
Hi,

Heikki recently (April 3rd) reported some of these bugs, here are the results of tests I have
run in 4.1. They are worrying and we probably have to fix this.

M is a MyISAM table, I an InnoDB table.

1) First bug

MASTER> reset master;
Query OK, 0 rows affected (0.00 sec)

MASTER> truncate table M;
Query OK, 0 rows affected (0.00 sec)

MASTER> truncate table I;
Query OK, 0 rows affected (0.00 sec)

MASTER> begin;
Query OK, 0 rows affected (0.00 sec)

MASTER> insert into I values(10);
Query OK, 1 row affected (0.00 sec)

MASTER> show binlog events;
| gbichot-bin.000001 |  79 | Query      |         1 |           79 | use `test`; truncate table M

MASTER> insert into M select * from I;
Query OK, 1 row affected (0.02 sec)
Records: 1  Duplicates: 0  Warnings: 0

MASTER> show binlog events;
| gbichot-bin.000001 |  79 | Query      |         1 |           79 | use `test`; truncate table M
| gbichot-bin.000001 | 130 | Query      |         1 |          130 | use `test`; insert into M select * from I        |

MASTER> select * from I;
+------+
| a    |
+------+
|   10 |
+------+
1 row in set (0.00 sec)

MASTER> rollback;
Query OK, 0 rows affected (0.00 sec)

MASTER> select * from I;
+------+
| a    |
+------+
|   10 |
+------+
1 row in set (0.00 sec)

MASTER> show binlog events;
| gbichot-bin.000001 |  79 | Query      |         1 |           79 | use `test`; truncate table M

As you see, updating a MyISAM table inside a transaction silently commits the
transaction, which is very good. But the cached binlog lines are never written to the file binlog (because of ROLLBACK), so insert into I values(10);
is lost, while it affected M, and the slave is different from the master =>bug.

2) Another one (the same but with COMMIT instead of ROLLBACK) :

MASTER> reset master;
Query OK, 0 rows affected (0.00 sec)

MASTER> begin;
Query OK, 0 rows affected (0.00 sec)

MASTER> truncate table M;
Query OK, 0 rows affected (0.00 sec)

MASTER> truncate table I;
Query OK, 1 row affected (0.00 sec)

MASTER> insert into I values(10);
Query OK, 1 row affected (0.00 sec)

MASTER> insert into M select * from I;
Query OK, 1 row affected (0.01 sec)
Records: 1  Duplicates: 0  Warnings: 0

MASTER> show binlog events;
| gbichot-bin.000001 |  79 | Query      |         1 |           79 | use `test`; truncate table M

MASTER> commit;
Query OK, 0 rows affected (0.00 sec)

MASTER> show binlog events;
| gbichot-bin.000001 |  79 | Query      |         1 |           79 | use `test`; truncate table M
| gbichot-bin.000001 | 130 | Query      |         1 |          130 | use `test`; insert into M select * from I        |
| gbichot-bin.000001 | 194 | Query      |         1 |          194 | use `test`; BEGIN
| gbichot-bin.000001 | 234 | Query      |         1 |          130 | use `test`; truncate table I
| gbichot-bin.000001 | 285 | Query      |         1 |          130 | use `test`; insert into I values(10)
| gbichot-bin.000001 | 344 | Query      |         1 |          344 | use `test`; COMMIT

As you see order is wrong and this breaks replication as well.

3) Another one :

MASTER> reset master;
Query OK, 0 rows affected (0.00 sec)

MASTER> truncate table M;
Query OK, 0 rows affected (0.00 sec)

MASTER> truncate table I;
Query OK, 1 row affected (0.01 sec)

MASTER> begin;
Query OK, 0 rows affected (0.00 sec)

MASTER> insert into I select * from M;
Query OK, 0 rows affected (0.00 sec)
Records: 0  Duplicates: 0  Warnings: 0

MASTER> commit;
Query OK, 0 rows affected (0.00 sec)

MASTER> select * from I;
Empty set (0.00 sec)

MASTER> show binlog events;
| gbichot-bin.000001 |  79 | Query      |         1 |           79 | use `test`; truncate table M
| gbichot-bin.000001 | 130 | Query      |         1 |          130 | use `test`; truncate table I
| gbichot-bin.000001 | 181 | Query      |         1 |          181 | use `test`; insert into M values(1000)
| gbichot-bin.000001 | 242 | Query      |         1 |          242 | use `test`; BEGIN
| gbichot-bin.000001 | 282 | Query      |         1 |          181 | use `test`; insert into I select * from M        |
| gbichot-bin.000001 | 346 | Query      |         1 |          346 | use `test`; COMMIT

Between the' insert into I select * from M;' and the 'commit;',
I opened another connection and did 'insert into M values(1000);'.
And this last INSERT was immediately written to the binlog, hence the bad order. The last INSERT could have been blocked by read-locking M when the INSERT SELECT was issued.
As you see the order in the binlog is wrong again.

How to repeat:

Suggested fix:
Proposed solutions :

To fix 1) and 2) : as there is a silent commit, do all what a real COMMIT does,
i.e. flush the cached binlog entry to the file binlog. Probably very easy to do.

To fix 3) : as we do when the SELECTed table is InnoDB : lock the SELECTed data
until the INSERT SELECT is commited. As the read table is MyISAM, this means
taking a READ lock on the MyISAM table.

I already sent an email to Monty for comments he may have.

Comment by Heikki:

Guilhem,

I recently changed the code in 4.0 so that an insert to a MyISAM table no
longer silently commits the InnoDB transaction:
ha_report_binlog_offset_and_commit() is no longer called if (1) we are
writing directly to the binlog and (2) there is data in the binlog cache of
the trx. That was because a user complained about that 'feature'.

This is one of the non fixable things when mixing transactional and non transactional tables.

I have update the manual to reflect this.

First and second bug could be fixed like this:
when, in a transaction, a non-transactional table is updated, write the statement to the binlog cache (don't immediately write the statement to binlog, like it is now, which is a serious bug); if rollback occurs, write the binlog cache to the binlog, but with a ending ROLLBACK.

sub-bugs 1 & 2 (i.e. the cases which are in a single connection) are fixed in
ChangeSet@1.1576.4.1, 2003-08-22 15:39:24+02:00, guilhem@mysql.com in MySQL 4.0.15.
sub-bug 3 (where 2 concurrent connections are involved) will not be fixed until we have row-level logging.