MySQL Bugs: #42189: falcon.falcon_bug_22211 fails due to blocked transaction sees rollbacked data

Bug #42189	falcon.falcon_bug_22211 fails due to blocked transaction sees rollbacked data
Submitted:	18 Jan 2009 22:05	Modified:	15 May 2009 15:49
Reporter:	Olav Sandstå	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Falcon storage engine	Severity:	S2 (Serious)
Version:	6.0.10-alpha	OS:	Any
Assigned to:	Olav Sandstå	CPU Architecture:	Any
Tags:	F_TRANSACTION

Description:
While trying to reproduce Bug#41391, test falcon_bug_22211 fails on the second test case when testing that a blocked transaction is alloweded to proceed if the blocking transaction is roll-backed to last savepoint. The error from the test is:

mysqltest: At line 102: query 'reap' failed: 1062: Duplicate entry '100' for key
 'PRIMARY'

The result from queries just before the failure was:
< snip >
SELECT * FROM t1;
a
100
# Switch to connection 1 (REPEATABLE READ)
START TRANSACTION;
SELECT * FROM t1;
a
0
# send INSERT (100) - This should SUCCEED after 100 is rolled back.
INSERT INTO t1 VALUES(100);;
# Switch to connection default (REPEATABLE READ)
# Rollback the value 100
ROLLBACK TO SAVEPOINT sp1;
# Commit the value 10
COMMIT;
SELECT * FROM t1;
a
10
# Switch to connection 1 (REPEATABLE READ)
# reap - INSERT (100)

This might be the same cause as for Bug#41391 or a different error.

How to repeat:
Re-run test falcon_bug_22211 "a few times" - this crash happened on re-run number 71507 of the test.

Suggested fix:
A transaction blocked due to waiting for second transaction that have inserted the same record should not see the data of the second transaction if the second transaction does a rollback to save-point.

Hi Miguel, Sorry for not including branch information:

The source code I use was checked out from the mysql-6.0-falcon-team tree on Friday January 16th and have revision number 2963.

Thank you for the feedback. I tried several times and I couldn't repeat with latest source tree, could you please test again. I ran the test on 64-bit Suse 11.1:

Installing Master Database
Saving snapshot of installed databases
=======================================================

TEST                           RESULT         TIME (ms)
-------------------------------------------------------

falcon.falcon_bug_22211        [ pass ]            104
falcon.falcon_bug_22211        [ pass ]            110
falcon.falcon_bug_22211        [ pass ]             96
falcon.falcon_bug_22211        [ pass ]            141
falcon.falcon_bug_22211        [ pass ]            117
falcon.falcon_bug_22211        [ pass ]            112
falcon.falcon_bug_22211        [ pass ]             95
falcon.falcon_bug_22211        [ pass ]             96
falcon.falcon_bug_22211        [ pass ]            109
falcon.falcon_bug_22211        [ pass ]            106
falcon.falcon_bug_22211        [ pass ]            132
falcon.falcon_bug_22211        [ pass ]            123
falcon.falcon_bug_22211        [ pass ]            109
falcon.falcon_bug_22211        [ pass ]            105
falcon.falcon_bug_22211        [ pass ]            115
falcon.falcon_bug_22211        [ pass ]            160
falcon.falcon_bug_22211        [ pass ]            111
falcon.falcon_bug_22211        [ pass ]            110
falcon.falcon_bug_22211        [ pass ]             99
falcon.falcon_bug_22211        [ pass ]             96
falcon.falcon_bug_22211        [ pass ]             97
falcon.falcon_bug_22211        [ pass ]             98
falcon.falcon_bug_22211        [ pass ]            104
falcon.falcon_bug_22211        [ pass ]             97
falcon.falcon_bug_22211        [ pass ]            115
falcon.falcon_bug_22211        [ pass ]            111
falcon.falcon_bug_22211        [ pass ]            109
falcon.falcon_bug_22211        [ pass ]            112
falcon.falcon_bug_22211        [ pass ]            117
falcon.falcon_bug_22211        [ pass ]            137
falcon.falcon_bug_22211        [ pass ]            172
falcon.falcon_bug_22211        [ pass ]            138
falcon.falcon_bug_22211        [ pass ]            116
falcon.falcon_bug_22211        [ pass ]             98
falcon.falcon_bug_22211        [ pass ]            100
falcon.falcon_bug_22211        [ pass ]            107
-------------------------------------------------------
Stopping All Servers
All 36 tests were successful.

Hi, I am not sure how easy it is to reproduce this crash. As I mentioned in the initial bug report the crash happened on re-run number 71507 of this test - and I have only seen the crash once,

When I got it I ran the debug-build of MySQL on a dual CPU AMD server running Solaris 10 MU5.

Setting this to Analysing until I have been able to reproduce it.

Setting this to verified based on that I have been able to reproduce it by running this test 184052 times using the latest sources from the mysql-6.0-falcon-team tree.

To my surprise, I found that there is NO sleep after the
--send INSERT INTO t1 VALUES(10);
Please add a --real_sleep 1 after the --send and before 
the following ROLLBACK.

--send INSERT INTO t1 VALUES(10);
--echo # Switch to connection default (REPEATABLE READ)
connection default;
--echo # Rollback the value 100
--real_sleep 1   <-- Add this and try to recreate
ROLLBACK TO SAVEPOINT sp1;
--echo # Commit the value 10
COMMIT;

This bug seems to have been fixed by the new Cycle Manager and the new Transaction State object that was introduced into Falcon about a month ago. I have re-run the test 484.000 times without seeing any crashes.

Fix is in 6.0.11

An entry has been added to the 6.0.11 changelog: 

The Falcon CycleManager has been updated, which addresses a number of issues when examining records in various transaction states and their visisbility/isolation in relation to other threads.