MySQL Bugs: #26116: If multi-row INSERT DELAYED has errors, statement-based binlogging breaks

Bug #26116	If multi-row INSERT DELAYED has errors, statement-based binlogging breaks
Submitted:	6 Feb 2007 14:23	Modified:	21 Jun 2010 0:56
Reporter:	Guilhem Bichot	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	4.0,4.1,5.0,5.1	OS:	Linux (linux)
Assigned to:	Guilhem Bichot	CPU Architecture:	Any

Description:
When INSERT DELAYED VALUES <several rows> is run, all rows are put into a queue; the first of them has the query attached to it (in the form of the "row->query" member, see sql_insert.cc).
Then the queue is processed by a system thread.
If the first row then fails (duplicate key), the query is never binlogged ("row->log_query= 0") but the other rows are tried for insertion so may succeed.
So this makes the binlog inconsistent with the data, silently breaks replication or recovery from binlogs.
If alternatively the first row succeeds, the query is binlogged immediately (so, with an error code of 0 which means "all the query went ok")), and if then another row fails, then the slave, which converts INSERT DELAYED to plain INSERT (as is necessary for serial execution of the binlog) will probably experience the same failure and so will stop, saying that it failed part of the query because of a duplicate key error (whereas if the master had recorded in the binlog that it failed part of the query, slave would have considered the failure as expected and thus not stopped).
So, in both cases, replication breaks (silently or not) and requires some manual investigation.

How to repeat:
For first case:
create table t1(id int, name char(5), unique (name)) engine=myisam;
insert into t1 values(1,"gb");
insert delayed into t1 values(1,"gb"),(2,"ab");
select * from t1;
+------+------+
| id   | name |
+------+------+
|    1 | gb   |
|    2 | ab   |
+------+------+
show binlog events;
+-------------------+-----+-------------+-----------+-------------+--------------------------------------------------------------------------------+
| Log_name          | Pos | Event_type  | Server_id | End_log_pos | Info                                                                           |
+-------------------+-----+-------------+-----------+-------------+--------------------------------------------------------------------------------+
| master-bin.000001 |   4 | Format_desc |         1 |          98 | Server ver: 5.0.36-valgrind-max-debug-log, Binlog ver: 4                       |
| master-bin.000001 |  98 | Query       |         1 |         227 | use `test`; create table t1(id int, name char(5), unique (name)) engine=myisam |
| master-bin.000001 | 227 | Query       |         1 |         319 | use `test`; insert into t1 values(1,"gb")                                      |
+-------------------+-----+-------------+-----------+-------------+--------------------------------------------------------------------------------+
3 rows in set (0.00 sec)
See: "ab" is in the table but not in the binlog.
For the second case:
create table t1(id int, name char(5), unique (name)) engine=myisam;
insert into t1 values(1,"gb");
insert delayed into t1 values(1,"ab"),(2,"gb");
select * from t1;
+------+------+
| id   | name |
+------+------+
|    1 | gb   |
|    1 | ab   |
+------+------+
on slave:
070206 17:50:35 [ERROR] Slave: Error 'Duplicate entry 'gb' for key 1' on query. Default database: 'test'. Query: 'insert delayed into t1 values(1,"ab"),(2,"gb")', Error_code: 1062
070206 17:50:35 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000001' position 319

Suggested fix:
SIMPLE EASY SOLUTION

Given that in 5.1, the default binlogging mode is "mixed binlogging", where INSERT DELAYED is binlogged row-based and thus does not have any of the problems above, from the point of view of most users, 5.1 does not have those bugs, and thus consider a simple fix for 5.0 and 5.1-in-statement-based-binlogging, which would be that a multi-row INSERT DELAYED is automatically converted to a multi-row plain INSERT (note that this is already true for INSERT DELAYED SELECT since 4.0, BUG#1983).
As an optimization we could do this conversion only if statement-based binlogging is on (which is quite frequent in 5.0 and quite rare in 5.1).
If we fix the bug this way, BUG#25507 "multi-row insert delayed + auto increment causes duplicate key entries on slave" will automatically be fixed.

LONG SOLUTION

Instead of binlogging after inserting first row of the statement, binlog after inserting last row of the statement. This allows to know if some error was hit when inserting rows of the statement (thus the error code can be stored in the binlog).
When having an error when inserting a row, don't decide to not binlog the statement; do binlog it, at the end.
Fix BUG#25507 the long way too.

patch at http://lists.mysql.com/commits/19619 (common with BUG#25507)

approved in the same patch as BUG#25507 (same code fix).

queued to 5.0-rpl and 5.1-rpl.
For doc info, please see BUG#25507, as one single small code change fixed the two bugs.

A note has been added tot he 5.0.38 and 5.1.17 changelogs.

Pushed into 5.1.47 (revid:joro@sun.com-20100505145753-ivlt4hclbrjy8eye) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)

Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug. Re-closing.

Pushed into mysql-next-mr (revid:alik@sun.com-20100524190136-egaq7e8zgkwb9aqi) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (pib:16)

Pushed into 6.0.14-alpha (revid:alik@sun.com-20100524190941-nuudpx60if25wsvx) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)

Pushed into 5.5.5-m3 (revid:alik@sun.com-20100524185725-c8k5q7v60i5nix3t) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)

Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug.
Re-closing.

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)

Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)

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)