Bug #61579 replication failure while innodb_autoinc_lock_mode=1 and using trigger
Submitted: 21 Jun 2011 11:27 Modified: 17 May 2012 18:13
Reporter: Hao Wu Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.1.57, 5.5.14 OS:Linux (CentOS 5.5)
Assigned to: CPU Architecture:Any
Triage: Needs Triage: D2 (Serious)

[21 Jun 2011 11:27] Hao Wu
Description:
innodb_autoinc_lock_mode is 1. While one session is inserting multiple rows into a a table with auto_increment key and after insert trigger, another session insert a row into the same table, then it will cause "duplicate key error" on slave.

How to repeat:
on master:

mysql [localhost] {msandbox} (test) > create table t (id int auto_increment primary key, a int) engine=innodb;
Query OK, 0 rows affected (0.02 sec)

mysql [localhost] {msandbox} (test) > create table th (id int  primary key, a int) engine=innodb;
Query OK, 0 rows affected (0.01 sec)

mysql [localhost] {msandbox} (test) > create trigger t_ai after insert on t for each row insert into th set id = new.id, a = new.a;
Query OK, 0 rows affected (0.01 sec)

then run the attached script, you may change some parameters to make two processes insert simultaneously.

on master:

mysql [localhost] {msandbox} (test) > select * from t where a = 2;
+-----+------+
| id  | a    |
+-----+------+
| 513 |    2 |
+-----+------+
1 row in set (0.00 sec)

on slave, it has the error of "Duplicate entry '513'".

The binlog on master is something like this:

# at 174
#110621 19:07:44 server id 1  end_log_pos 202   Intvar
SET INSERT_ID=1/*!*/;
# at 202
#110621 19:07:44 server id 1  end_log_pos 293   Query   thread_id=4     exec_time=0     error_code=0
use test/*!*/;
SET TIMESTAMP=1308654464/*!*/;
insert into t (a) values (1)
/*!*/;
# at 293
#110621 19:07:44 server id 1  end_log_pos 320   Xid = 4
COMMIT/*!*/;
# at 320
#110621 19:07:44 server id 1  end_log_pos 388   Query   thread_id=4     exec_time=0     error_code=0
SET TIMESTAMP=1308654464/*!*/;
BEGIN
/*!*/;
# at 388
#110621 19:07:44 server id 1  end_log_pos 416   Intvar
SET INSERT_ID=513/*!*/;
# at 416
#110621 19:07:44 server id 1  end_log_pos 507   Query   thread_id=4     exec_time=0     error_code=0
SET TIMESTAMP=1308654464/*!*/;
insert into t (a) values (2)
/*!*/;
# at 507
#110621 19:07:44 server id 1  end_log_pos 534   Xid = 338
COMMIT/*!*/;
# at 534
#110621 19:07:44 server id 1  end_log_pos 602   Query   thread_id=4     exec_time=0     error_code=0
SET TIMESTAMP=1308654464/*!*/;
BEGIN
/*!*/;
# at 602
#110621 19:07:44 server id 1  end_log_pos 630   Intvar
SET INSERT_ID=1026/*!*/;
# at 630
#110621 19:07:44 server id 1  end_log_pos 721   Query   thread_id=4     exec_time=0     error_code=0
SET TIMESTAMP=1308654464/*!*/;
insert into t (a) values (3)
/*!*/;
# at 721
#110621 19:07:44 server id 1  end_log_pos 748   Xid = 579
COMMIT/*!*/;
# at 748
#110621 19:07:44 server id 1  end_log_pos 816   Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1308654464/*!*/;
BEGIN
/*!*/;
# at 816
#110621 19:07:44 server id 1  end_log_pos 844   Intvar
SET INSERT_ID=2/*!*/;
# at 844
#110621 19:07:44 server id 1  end_log_pos 80939         Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1308654464/*!*/;
insert into t (a) values (10000),(10001),...
[21 Jun 2011 11:29] Hao Wu
script to reproduce the bug

Attachment: bug_61579.pl (application/octet-stream, text), 434 bytes.

[21 Jun 2011 11:29] Hao Wu
script to reproduce the bug

Attachment: bug_61579.pl (application/octet-stream, text), 434 bytes.

[21 Jun 2011 11:32] Hao Wu
Sorry for duplicate upload. It can be reproduced on 5.6.2-m5 too.
[22 Jun 2011 12:56] Miguel Solorzano
Could you please provide the my.cnf files for master and slave. Thanks.
[23 Jun 2011 1:43] Hao Wu
cnf of master

Attachment: my.master.cnf (application/octet-stream, text), 1.72 KiB.

[23 Jun 2011 1:44] Hao Wu
cnf of slave

Attachment: my.slave.cnf (application/octet-stream, text), 1.76 KiB.

[13 Jul 2011 19:56] Sveta Smirnova
Thank you for the feedback.

Verified as described.
[17 May 2012 18:13] John Russell
Added to changelog for 5.1.64, 5.5.26, 5.6.6: 

For an InnoDB table with a trigger, under the setting
innodb_autoinc_lock_mode=1, sometimes auto-increment values could be
interleaved when inserting into the table from two sessions
concurrently. The sequence of auto-increment values could vary
depending on timing, leading to data inconsistency in systems using
replication.