MySQL Bugs: #66134: InnoDB tables under load produce duplicate copies of rows in queries

Bug #66134	InnoDB tables under load produce duplicate copies of rows in queries
Submitted:	1 Aug 2012 1:33	Modified:	18 Oct 2012 22:54
Reporter:	Graham Lea	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S1 (Critical)
Version:	5.5.25a, 5.5.28	OS:	Any (Linux 3.2.0-27-generic #43-Ubuntu SMP x86_64 GNU/Linux (and others))
Assigned to:		CPU Architecture:	Any
Tags:	duplicate, query, regression

Description:
An InnoDB table that:
a) is constrained to only contain unique values; and
b) is being frequently updated with inserts and deletes; and 
c) is also frequently queried
is producing query results that contain duplicates that, according to the constraint, should never exist in the data.

A simple test case has been produced and used to verify that this behaviour is a regression since 5.5.15 (our previous version).

How to repeat:
1) Download the attached script
2) Modify the lines at the beginning of the script to match your database setup:
        DB_DATABASE=YOUR_DATABASE
        DB_USER=YOUR_USER
        DB_PASSWORD=YOUR_PASSWORD
3) Run the script

What the script does:
1) Creates a table in the specified database containing a single column:
create table concurrent_test_table (id bigint(20) AUTO_INCREMENT PRIMARY KEY);
2) Creates three scripts under /tmp/ : one that performs lots of INSERTs into the table, one that performs lots of DELETEs on the table, and one that performs lots of SELECTs on the table. The SELECT only produces output if the query returns a non-unique ID, i.e. two rows in the result with the same ID.
3) Each of the 3 scripts is run forever in the background.

EXPECTED OUTPUT:

On 5.5.15, the scripts only output the time and some other info about once every 5 minutes, like so:

*************************** 1. row ***************************
            NOW(): 2012-08-01 10:47:44
          min(id): NULL
          max(id): NULL
max(id) - min(id): NULL

*************************** 1. row ***************************
            NOW(): 2012-08-01 10:53:54
          min(id): 2948505
          max(id): 2948506
max(id) - min(id): 1

ACTUAL OUTPUT:

On 5.5.25a, the queries against the test table regularly receive duplicate IDs from the test table and output these, which looks like this:

*************************** 1. row ***************************
            NOW(): 2012-08-01 10:45:51
          min(id): NULL
          max(id): NULL
max(id) - min(id): NULL
id	count(T1.id)
47205	2
id	count(T1.id)
81111	2
id	count(T1.id)
81717	2
id	count(T1.id)
172189	2

Suggested fix:
It seems possible that this bug was introduced when the fixes for Bug #13817703, Bug #61209 were put in to 5.5.23 and 5.5.24.

BASH script that reproduces the problem

Attachment: mysql_bug_reproduction_clean.sh (application/x-shellscript, text), 1.71 KiB.

Apparently Bug #13817703 doesn't exist, although it is cited in the release notes for 5.5.23 and 5.5.24:
http://dev.mysql.com/doc/refman/5.5/en/news-5-5-23.html
http://dev.mysql.com/doc/refman/5.5/en/news-5-5-24.html

Note that the test case assumes the default storage engine on the DB is InnoDB.

For the benefit of others that may have similar problems, Hibernate was giving us error messages like this:
"org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1"
when we were pulling back a list of entities and then updating them.

It was also giving us this one: 
"org.hibernate.HibernateException: More than one row with the given identifier was found: 122606513, for class:"
while trying to retrieve a related entity based on a foreign key.

In both of these scenarios, there is no code path that would result in duplicate values in the tables, but the most plausible explanation for the behaviour was that MySQL was returning duplicates of single rows.

Verified just as described with recent mysql-5.5 from bzr on Mac OS X:

macbook-pro:5.5 openxs$ bash ~/Downloads/mysql_bug_reproduction_clean.sh 
Creating table concurrent_test_table ...
Creating scripts ...
    /tmp/concurrent_test_table_insert.sql
    /tmp/concurrent_test_table_delete.sql
    /tmp/concurrent_test_table_query.sql
Running scripts in background ...
Press CTRL-C to exit.

*************************** 1. row ***************************
            NOW(): 2012-08-01 16:50:51
          min(id): 2
          max(id): 2
max(id) - min(id): 0
id	count(T1.id)
6407	2
id	count(T1.id)
9940	2
^CTerminated

Added to changelog for 5.1.66, 5.5.28, 5.6.7, 5.7.0: 

Under heavy load of concurrent DML and queries, an InnoDB table with
a unique index could return non-existent duplicate rows to a query.