Bug #29571 INSERT DELAYED IGNORE written to binary log on the master but on the slave
Submitted: 5 Jul 2007 12:06 Modified: 3 Aug 2007 15:39
Reporter: Victoria Reznichenko Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:4.1,5.0 OS:Any
Assigned to: Georgi Kodinov CPU Architecture:Any
Tags: bfsm_2007_07_19

[5 Jul 2007 12:06] Victoria Reznichenko
Description:
Slave is running with --log-slave-updates option.
If INSERT DELAYED IGNORE skipped on the master due to unique key violation it is still written to binary log as is. However when this statement is executed on the slave by replication thread (and it is skipped too) it doesn't go to binary logs. As a result - different binary log content on the master and on the slave.

This is snip from binary log on master:

SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
CREATE TABLE t1(
id int,
UNIQUE(id))/*!*/;
# at 197
#070705 16:18:35 server id 1  end_log_pos 299   Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1183637915/*!*/;
INSERT DELAYED IGNORE INTO t1 VALUES(1)/*!*/;
# at 299
#070705 16:18:35 server id 1  end_log_pos 401   Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1183637915/*!*/;
INSERT DELAYED IGNORE INTO t1 VALUES(2)/*!*/;
# at 401
#070705 16:18:35 server id 1  end_log_pos 503   Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1183637915/*!*/;
INSERT DELAYED IGNORE INTO t1 VALUES(2)/*!*/;
# at 503
#070705 16:18:36 server id 1  end_log_pos 605   Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1183637916/*!*/;
INSERT DELAYED IGNORE INTO t1 VALUES(3)/*!*/;

As you can see "INSERT DELAYED IGNORE INTO t1 VALUES(2)" appears twice in master binary log.

Below is snip from the slave binary log:

CREATE TABLE t1(
id int,
UNIQUE(id))/*!*/;
# at 197
#070705 16:18:35 server id 1  end_log_pos 299   Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1183637915/*!*/;
INSERT DELAYED IGNORE INTO t1 VALUES(1)/*!*/;
# at 299
#070705 16:18:35 server id 1  end_log_pos 401   Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1183637915/*!*/;
INSERT DELAYED IGNORE INTO t1 VALUES(2)/*!*/;
# at 401
#070705 16:18:36 server id 1  end_log_pos 503   Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1183637916/*!*/;
INSERT DELAYED IGNORE INTO t1 VALUES(3)/*!*/;

How to repeat:
1. setup master-slave replication. slave should be running with --log-slave-updates option
2. create simple table with unique key
3. insert several rows with duplicate values
4. check binary log content on the master and on the slave

test table:

CREATE TABLE t1(
id int,
UNIQUE(id));
INSERT DELAYED IGNORE INTO t1 VALUES(1);
INSERT DELAYED IGNORE INTO t1 VALUES(2);
INSERT DELAYED IGNORE INTO t1 VALUES(2);
INSERT DELAYED IGNORE INTO t1 VALUES(3);

Suggested fix:
Those INSERTs should be either written to the master and to the slave binary logs or omited in both.
[25 Jul 2007 17:11] 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/31550

ChangeSet@1.2486, 2007-07-25 20:10:53+03:00, gkodinov@magare.gmz +3 -0
  Bug #29571: INSERT DELAYED IGNORE written to binary log on 
   the master but on the slave
  
  MySQL can decide to "downgrade" a INSERT DELAYED statement
  to normal insert in certain situations.
  One such situation is when the slave is replaying a 
  replication feed.
  However INSERT DELAYED is logged even if there're no updates
  whereas the NORMAL INSERT is not logged in such cases.
  
  Fixed by always logging a "downgraded" INSERT DELAYED: even 
  if there were no updates.
[26 Jul 2007 8:31] 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/31598

ChangeSet@1.2486, 2007-07-26 11:31:10+03:00, gkodinov@magare.gmz +3 -0
  Bug #29571: INSERT DELAYED IGNORE written to binary log on 
   the master but on the slave
  
  MySQL can decide to "downgrade" a INSERT DELAYED statement
  to normal insert in certain situations.
  One such situation is when the slave is replaying a 
  replication feed.
  However INSERT DELAYED is logged even if there're no updates
  whereas the NORMAL INSERT is not logged in such cases.
  
  Fixed by always logging a "downgraded" INSERT DELAYED: even 
  if there were no updates.
[2 Aug 2007 19:14] Bugs System
Pushed into 5.1.21-beta
[2 Aug 2007 19:15] Bugs System
Pushed into 5.0.48
[3 Aug 2007 15:39] Paul DuBois
Noted in 5.0.48, 5.1.21 changelogs.

A slave running with --log-slave-updates would fail to write INSERT
DELAY IGNORE statements to its binary log, resulting in different
binary log contents on the master and slave.