MySQL Bugs: #65111: Innodb sometimes fails to update rows inserted by a concurrent transaction

Bug #65111	Innodb sometimes fails to update rows inserted by a concurrent transaction
Submitted:	26 Apr 2012 9:31	Modified:	15 May 2012 18:33
Reporter:	Simon Martin	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: InnoDB Plugin storage engine	Severity:	S2 (Serious)
Version:	5.6,5.5	OS:	Linux
Assigned to:		CPU Architecture:	Any
Tags:	innodb, regression, transaction

Description:
In some circumstances InnoDB will not update a row recently inserted and committed by another concurrent transaction:

#Set up
mysql> DROP TABLE IF EXISTS `update_bug`;
Query OK, 0 rows affected (0.00 sec)

mysql> CREATE TABLE `update_bug` (
    ->   `id` int(11) PRIMARY KEY AUTO_INCREMENT,
    ->   `fk_id` int(11) DEFAULT NULL,
    ->   `start_time` timestamp NOT NULL DEFAULT '0000-00-00 00:00:00',
    ->   `end_time` timestamp NULL DEFAULT NULL,
    ->   KEY `ub_ix1` (`fk_id`,`end_time`),
    ->   KEY `ub_ix2` (`end_time`)
    -> ) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;
Query OK, 0 rows affected (0.03 sec)

mysql> INSERT INTO `update_bug` (fk_id, start_time, end_time) VALUES (1, '1999-12-31 23:59:59', '1999-12-31 23:59:59'), (1, '1999-12-31 23:59:59', NULL);
Query OK, 2 rows affected (0.00 sec)
Records: 2  Duplicates: 0  Warnings: 0

#Start first transaction in session 1
mysql> START TRANSACTION WITH CONSISTENT SNAPSHOT;
Query OK, 0 rows affected (0.00 sec)

#Start and run transaction in Session 2
mysql> START TRANSACTION WITH CONSISTENT SNAPSHOT;
Query OK, 0 rows affected (0.00 sec)

mysql> UPDATE update_bug SET end_time = '2000-01-01 00:00:02' WHERE fk_id = 1 AND end_time IS NULL;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> INSERT INTO update_bug (fk_id, start_time, end_time) VALUES (1, '2000-01-01 00:00:02', NULL);
Query OK, 1 row affected (0.00 sec)

mysql> COMMIT;
Query OK, 0 rows affected (0.01 sec)

#Finish transaction in session 1
mysql> UPDATE update_bug SET end_time = '2000-01-01 00:00:01' WHERE fk_id = 1 AND end_time IS NULL;
Query OK, 0 rows affected (0.00 sec)
Rows matched: 0  Changed: 0  Warnings: 0

mysql> INSERT INTO update_bug (fk_id, start_time, end_time) VALUES (1, '2000-01-01 00:00:01', NULL);
Query OK, 1 row affected (0.00 sec)

mysql> COMMIT;
Query OK, 0 rows affected (0.00 sec)

The update in session 1 does not report updating any rows, and this is confirmed in the table:
mysql> SELECT * FROM update_bug;
+----+-------+---------------------+---------------------+
| id | fk_id | start_time          | end_time            |
+----+-------+---------------------+---------------------+
|  1 |     1 | 1999-12-31 23:59:59 | 1999-12-31 23:59:59 |
|  2 |     1 | 1999-12-31 23:59:59 | 2000-01-01 00:00:02 |
|  3 |     1 | 2000-01-01 00:00:02 | NULL                |
|  4 |     1 | 2000-01-01 00:00:01 | NULL                |
+----+-------+---------------------+---------------------+
4 rows in set (0.00 sec)

The update in session 1 should update the recently inserted and committed row from session 2. This causes incorrect data on the server, and if replication is enabled causes slaves to diverge with MIXED or STATEMENT replication as after serialisation to the binlogs the newly inserted row is updated correctly on slaves.

This bug is not observable if the following changes are made to the test case:
 - The table is empty at the start of the test (i.e. skip the INSERT after the CREATE)
 - Either or both the non-primary indexes are removed
 - Use an isolation level other than REPEATABLE READ

How to repeat:
DROP TABLE IF EXISTS `update_bug`;
CREATE TABLE `update_bug` (
  `id` int(11) PRIMARY KEY AUTO_INCREMENT,
  `fk_id` int(11) DEFAULT NULL,
  `start_time` timestamp NOT NULL DEFAULT '0000-00-00 00:00:00',
  `end_time` timestamp NULL DEFAULT NULL,
  KEY `ub_ix1` (`fk_id`,`end_time`),
  KEY `ub_ix2` (`end_time`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;
INSERT INTO `update_bug` (fk_id, start_time, end_time) VALUES (1, '1999-12-31 23:59:59', '1999-12-31 23:59:59'), (1, '1999-12-31 23:59:59', NULL);

#Session 1
START TRANSACTION WITH CONSISTENT SNAPSHOT;

#Session 2
START TRANSACTION WITH CONSISTENT SNAPSHOT;
UPDATE update_bug SET end_time = '2000-01-01 00:00:02' WHERE fk_id = 1 AND end_time IS NULL;
INSERT INTO update_bug (fk_id, start_time, end_time) VALUES (1, '2000-01-01 00:00:02', NULL);
COMMIT;

#Session 1
UPDATE update_bug SET end_time = '2000-01-01 00:00:01' WHERE fk_id = 1 AND end_time IS NULL;
INSERT INTO update_bug (fk_id, start_time, end_time) VALUES (1, '2000-01-01 00:00:01', NULL);
COMMIT;

Thank you for taking the time to write to us, but this is not a bug. Please double-check the documentation available at http://dev.mysql.com/doc/ and the instructions on
how to report a bug at http://bugs.mysql.com/how-to-report.php

You start transaction with option "WITH CONSISTENT SNAPSHOT". According to http://dev.mysql.com/doc/refman/5.5/en/commit.html: "The WITH CONSISTENT SNAPSHOT option starts a consistent read for storage engines that are capable of it. This applies only to InnoDB. The effect is the same as issuing a START TRANSACTION followed by a SELECT from any InnoDB table. "

This means transaction 1 "read" all rows from the table when transaction started and to be able to satisfy REPEATABLE READ conditions it does not see row inserted in the another transaction.

If this is not a bug can you explain why the behaviour changes by adding or removing the indexes? Either the row should always be updated (as I believe) or the row should never be updated. The behaviour should be consistent regardless of the presence of these indexes, at the moment it is not.

Thank you for the feedback.

I agree with key usage inconsistency. Set as "Verified".

In versions 5.0 and 5.1 results are same (first transaction sees row) regardless from secondary key usage.

Bug not repeatable with 5.1 for me today, but repeatable with 5.5 and trunk

Sorry for the delay - I agree, can not reproduce in 5.1, removing it from the effected versions.

Added to changelog for 5.1.64, 5.5.25, 5.6.6: 
 
 In a transaction using the REPEATABLE READ isolation level, an UPDATE
 or DELETE statement for an InnoDB table could sometimes overlook rows
 recently committed by other transactions. As explained in innodb-consistent-read, DML
 statements within a REPEATABLE READ transaction apply to rows
 committed by other transactions, even if a query could not see those
 rows.