| Bug #69861 | LAST_INSERT_ID is replicated incorrectly if replication filters are used | ||
|---|---|---|---|
| Submitted: | 28 Jul 2013 9:37 | Modified: | 21 Oct 2013 14:55 |
| Reporter: | Miguel Angel Nieto | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S2 (Serious) |
| Version: | 5.5.32, 5.6.12/13 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
[28 Jul 2013 10:42]
Miguel Angel Nieto
Tested in latest 5.5.32.
[29 Jul 2013 10:04]
MySQL Verification Team
Hello Miguel, Thank you for the bug report and the test case. Verified as described. Thanks, Umesh
[29 Jul 2013 10:06]
MySQL Verification Team
// With the test case and replicate-ignore-table=database.table enabled
Last_Error: Error 'Cannot add or update a child row: a foreign key constraint fails (`test`.`sometable`, CONSTRAINT `sometable_apps` FOREIGN KEY (`appid`) REFERENCES `sometable_apps` (`id`))' on query. Default database: 'test'. Query: 'insert into sometable (rundt, appid, username, machine, pid) values ('2013-07-23 15:56:59', LAST_INSERT_ID(), 'xxxxx', 'xxxxxxx', 2736)'
Skip_Counter: 0
Exec_Master_Log_Pos: 1645
Relay_Log_Space: 1724
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: NULL
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 1452
Last_SQL_Error: Error 'Cannot add or update a child row: a foreign key constraint fails (`test`.`sometable`, CONSTRAINT `sometable_apps` FOREIGN KEY (`appid`) REFERENCES `sometable_apps` (`id`))' on query. Default database: 'test'. Query: 'insert into sometable (rundt, appid, username, machine, pid) values ('2013-07-23 15:56:59', LAST_INSERT_ID(), 'xxxxx', 'xxxxxxx', 2736)'
Replicate_Ignore_Server_Ids:
Master_Server_Id: 1
1 row in set (0.00 sec)
//
[root@cluster-repo C]# /data/ushastry/server/mysql-5.5.32/bin/mysqlbinlog C-relay-bin.000002 |grep -i "SET LAST_INSERT_ID"
SET LAST_INSERT_ID=0/*!*/;
// With the test case and replicate-ignore-table=database.table disabled
[root@cluster-repo C]# /data/ushastry/server/mysql-5.5.32/bin/mysqlbinlog C-relay-bin.000002 |grep -i "SET LAST_INSERT_ID"
SET LAST_INSERT_ID=1/*!*/;
[29 Jul 2013 12:41]
MySQL Verification Team
// 5.6.13 too affected
mysql> select version();
+------------+
| version() |
+------------+
| 5.6.13-log |
+------------+
1 row in set (0.00 sec)
mysql> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: localhost
Master_User: repl
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: mysql-bin.000003
Read_Master_Log_Pos: 2226
Relay_Log_File: C-relay-bin.000002
Relay_Log_Pos: 1313
Relay_Master_Log_File: mysql-bin.000003
Slave_IO_Running: Yes
Slave_SQL_Running: No
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table: database.table
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 1452
Last_Error: Error 'Cannot add or update a child row: a foreign key constraint fails (`test`.`sometable`, CONSTRAINT `sometable_apps` FOREIGN KEY (`appid`) REFERENCES `sometable_apps` (`id`))' on query. Default database: 'test'. Query: 'insert into sometable (rundt, appid, username, machine, pid) values ('2013-07-23 15:56:59', LAST_INSERT_ID(), 'xxxxx', 'xxxxxxx', 2736)'
Skip_Counter: 0
Exec_Master_Log_Pos: 1843
Relay_Log_Space: 1865
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: NULL
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 1452
Last_SQL_Error: Error 'Cannot add or update a child row: a foreign key constraint fails (`test`.`sometable`, CONSTRAINT `sometable_apps` FOREIGN KEY (`appid`) REFERENCES `sometable_apps` (`id`))' on query. Default database: 'test'. Query: 'insert into sometable (rundt, appid, username, machine, pid) values ('2013-07-23 15:56:59', LAST_INSERT_ID(), 'xxxxx', 'xxxxxxx', 2736)'
Replicate_Ignore_Server_Ids:
Master_Server_Id: 1
Master_UUID: 7d77c950-f901-11e2-9540-9d1696aea42d
Master_Info_File: /tmp/C/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State:
Master_Retry_Count: 86400
Master_Bind:
Last_IO_Error_Timestamp:
Last_SQL_Error_Timestamp: 130730 16:17:34
Master_SSL_Crl:
Master_SSL_Crlpath:
Retrieved_Gtid_Set:
Executed_Gtid_Set:
Auto_Position: 0
1 row in set (0.00 sec)
//
# /data/ushastry/server/mysql-5.5.32/bin/mysqlbinlog /tmp/C/C-relay-bin.000002 |grep -i "SET LAST_INSERT_ID"
SET LAST_INSERT_ID=0/*!*/;
[29 Jul 2013 15:04]
MySQL Verification Team
// enabled GTID mode.. and confirmed it still breaks replication on C
mysql> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: localhost
Master_User: repl
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: mysql-bin.000003
Read_Master_Log_Pos: 2689
Relay_Log_File: C-relay-bin.000002
Relay_Log_Pos: 1488
Relay_Master_Log_File: mysql-bin.000003
Slave_IO_Running: Yes
Slave_SQL_Running: No
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table: database.table
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 1452
Last_Error: Error 'Cannot add or update a child row: a foreign key constraint fails (`test`.`sometable`, CONSTRAINT `sometable_apps` FOREIGN KEY (`appid`) REFERENCES `sometable_apps` (`id`))' on query. Default database: 'test'. Query: 'insert into sometable (rundt, appid, username, machine, pid) values ('2013-07-23 15:56:59', LAST_INSERT_ID(), 'xxxxx', 'xxxxxxx', 2736)'
Skip_Counter: 0
Exec_Master_Log_Pos: 2258
Relay_Log_Space: 2119
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: NULL
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 1452
Last_SQL_Error: Error 'Cannot add or update a child row: a foreign key constraint fails (`test`.`sometable`, CONSTRAINT `sometable_apps` FOREIGN KEY (`appid`) REFERENCES `sometable_apps` (`id`))' on query. Default database: 'test'. Query: 'insert into sometable (rundt, appid, username, machine, pid) values ('2013-07-23 15:56:59', LAST_INSERT_ID(), 'xxxxx', 'xxxxxxx', 2736)'
Replicate_Ignore_Server_Ids:
Master_Server_Id: 1
Master_UUID: 09b63709-f919-11e2-95da-9c138a7dd2a7
Master_Info_File: /tmp/C/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State:
Master_Retry_Count: 86400
Master_Bind:
Last_IO_Error_Timestamp:
Last_SQL_Error_Timestamp: 130730 18:42:47
Master_SSL_Crl:
Master_SSL_Crlpath:
Retrieved_Gtid_Set: 0cfe5261-f919-11e2-95da-91e5cb490d63:6-9
Executed_Gtid_Set: 0cfe5261-f919-11e2-95da-91e5cb490d63:6-8
Auto_Position: 0
1 row in set (0.00 sec)
[21 Oct 2013 14:55]
Jon Stephens
Fixed in 5.1+. Documented in the MySQL 5.1.73, 5.5.35, 5.6.15, and 5.7.3 changelogs, as follows:
The value of LAST_INSERT_ID() was not correctly replicated when
filtering rules were used on the slave.
Closed.
[5 Dec 2013 6:42]
Laurynas Biveinis
5.1$ bzr log -r 4055
------------------------------------------------------------
revno: 4055
committer: Venkatesh Duggirala<venkatesh.duggirala@oracle.com>
branch nick: mysql-5.1
timestamp: Wed 2013-10-16 22:12:23 +0530
message:
Bug#17234370 LAST_INSERT_ID IS REPLICATED INCORRECTLY IF
REPLICATION FILTERS ARE USED.
Problem:
When Filtered-slave applies Int_var_log_event and when it
tries to write the event to its own binlog, LAST_INSERT_ID
value is written wrongly.
Analysis:
THD::stmt_depends_on_first_successful_insert_id_in_prev_stmt
is a variable which is set when LAST_INSERT_ID() is used by
a statement. If it is set, first_successful_insert_id_in_
prev_stmt_for_binlog will be stored in the statement-based
binlog. This variable is CUMULATIVE along the execution of
a stored function or trigger: if one substatement sets it
to 1 it will stay 1 until the function/trigger ends,
thus making sure that first_successful_insert_id_in_
prev_stmt_for_binlog does not change anymore and is
propagated to the caller for binlogging. This is achieved
using the following code
if(!stmt_depends_on_first_successful_insert_id_in_prev_stmt)
{
/* It's the first time we read it */
first_successful_insert_id_in_prev_stmt_for_binlog=
first_successful_insert_id_in_prev_stmt;
stmt_depends_on_first_successful_insert_id_in_prev_stmt= 1;
}
Slave server, after receiving Int_var_log_event event from
master, it is setting
stmt_depends_on_first_successful_insert_id_in_prev_stmt
to true(*which is wrong*) and not setting
first_successful_insert_id_in_prev_stmt_for_binlog. Because
of this problem, when the actual DML statement with
LAST_INSERT_ID() is parsed by slave SQL thread,
first_successful_insert_id_in_prev_stmt_for_binlog is not
set. Hence the value zero (default value) is written to
slave's binlog.
Why only *Filtered slave* is effected when the code is
in common place:
-------------------------------------------------------
In Query_log_event::do_apply_event,
THD::stmt_depends_on_first_successful_insert_id_in_prev_stmt
is reset to zero at the end of the function. In case of
normal slave (No Filters), this variable will be reset.
In Filtered slave, Slave SQL thread defers all IRU events's
execution until IRU's Query_log event is received. Once it
receives Query_log_event it executes all pending IRU events
and then it executes Query_log_event. Hence the variable is
not getting reset to 0, causing this bug.
Fix: As described above, the root cause was setting
THD::stmt_depends_on_first_successful_insert_id_in_prev_stmt
when Int_var_log_event was executed by a SQL thread. Hence
removing the problematic line from the code.
Description: If you have a replication environment that uses replication filters (replicate-ignore-table in this example), the value of LAST_INSERT_ID could not get correctly replicated. In the environment described in "how to repeat" this is the LAST_INSERT_ID value that the slave server receives without replicate-ignore-table: SET LAST_INSERT_ID=1/*!*/; And the same query with replicate-ignore-table writes the following on slave's relay log: SET LAST_INSERT_ID=0/*!*/; How to repeat: We have the following servers: A<->B | C Where A and B are in master-master and C replicates from A. Now run the following on B: CREATE TABLE `sometable_apps` ( `id` int(11) NOT NULL AUTO_INCREMENT, `appname` varchar(50) DEFAULT NULL, `createdate` datetime DEFAULT NULL, PRIMARY KEY (`id`) ) ENGINE=InnoDB; CREATE TABLE `sometable` ( `id` int(11) NOT NULL AUTO_INCREMENT, `rundt` datetime DEFAULT NULL, `appid` int(11) DEFAULT NULL, `username` varchar(20) DEFAULT NULL, `machine` varchar(20) DEFAULT NULL, `finishdt` datetime DEFAULT NULL, `pid` int(11) DEFAULT NULL, PRIMARY KEY (`id`), KEY `sometable_apps` (`appid`), CONSTRAINT `sometable_apps` FOREIGN KEY (`appid`) REFERENCES `sometable_apps` (`id`) ) ENGINE=InnoDB; insert into sometable_apps(appname, createdate) values ('xxxxx', '2013-07-23 15:56:59'); insert into sometable (rundt, appid, username, machine, pid) values ('2013-07-23 15:56:59', LAST_INSERT_ID(), 'xxxxx', 'xxxxxxx', 2736); The C's replication will fail: "Error 'Cannot add or update a child row: a foreign key constraint fails". If you remove the replicate-ignore-table and repeat the process it won't fail and the LAST_INSERT_ID will be correctly logged on slaves relay log. A SERVER: [client] user = msandbox password = msandbox port = 22987 socket = /tmp/mysql_sandbox22987.sock [mysqld] user = root port = 22987 socket = /tmp/mysql_sandbox22987.sock basedir = /root/5.5.32 datadir = /root/sandboxes/rsandbox_mysql-5_5_32/master/data tmpdir = /root/sandboxes/rsandbox_mysql-5_5_32/master/tmp pid-file = /root/sandboxes/rsandbox_mysql-5_5_32/master/data/mysql_sandbox22987.pid bind-address = 127.0.0.1 log-bin=mysql-bin server-id=1 log-error=msandbox.err replicate-ignore-table=database.table log-slave-updates = 1 B SERVER: [client] user = msandbox password = msandbox port = 22988 socket = /tmp/mysql_sandbox22988.sock [mysqld] user = root port = 22988 socket = /tmp/mysql_sandbox22988.sock basedir = /root/5.5.32 datadir = /root/sandboxes/rsandbox_mysql-5_5_32/node1/data tmpdir = /root/sandboxes/rsandbox_mysql-5_5_32/node1/tmp pid-file = /root/sandboxes/rsandbox_mysql-5_5_32/node1/data/mysql_sandbox22988.pid bind-address = 127.0.0.1 server-id=101 report-host=SBslave1 report-port=22988 log-bin=mysql-bin log-error=msandbox.err replicate-ignore-table=database.table log-slave-updates = 1 C SERVER: [client] user = msandbox password = msandbox port = 22989 socket = /tmp/mysql_sandbox22989.sock [mysqld] user = root port = 22989 socket = /tmp/mysql_sandbox22989.sock basedir = /root/5.5.32 datadir = /root/sandboxes/rsandbox_mysql-5_5_32/node2/data tmpdir = /root/sandboxes/rsandbox_mysql-5_5_32/node2/tmp pid-file = /root/sandboxes/rsandbox_mysql-5_5_32/node2/data/mysql_sandbox22989.pid bind-address = 127.0.0.1 server-id=102 report-host=SBslave2 report-port=22989 log-bin=mysql-bin log-error=msandbox.err replicate-ignore-table=database.table