Bug #43961 | Falcon assertion (false) in Table::rollbackRecord with no backlogging | ||
---|---|---|---|
Submitted: | 30 Mar 2009 14:45 | Modified: | 26 May 2010 17:47 |
Reporter: | Philip Stoev | Email Updates: | |
Status: | Unsupported | Impact on me: | |
Category: | MySQL Server: Falcon storage engine | Severity: | S1 (Critical) |
Version: | 6.0-falcon-team | OS: | Any |
Assigned to: | Kevin Lewis | CPU Architecture: | Any |
Tags: | F_RECORD TREE |
[30 Mar 2009 14:45]
Philip Stoev
[30 Mar 2009 14:45]
Philip Stoev
Log: http://loki41.norway.sun.com/~bteam/pb2/web_loki41.py?action=archive_download&archive_id=4... Push, core, source, binary: http://loki41.norway.sun.com/~bteam/pb2/web_loki41.py?template=push_details&push=306821&bu...
[2 Apr 2009 20:46]
Olav Sandstå
I got this crash with identical call stack when running the falcon_backlog test on the latest source from falcon team. The last lines from mysqld's log file contains: 727: Record thaw (fetch): table 25, 1 records, 2431 bytes 728: Record thaw (fetch): table 25, 1 records, 2206 bytes 728: Record thaw (fetch): table 25, 1 records, 2496 bytes 728: Record thaw (fetch): table 25, 1 records, 1726 bytes Table::rollbackRecord failed: 0x2aaaab0b0248 Id 15676, enc 4, state 6, tid 797, use 2, grp 4, prior 0 x2aaaab29adc8 0x2aaaab29adc8 Id 15676, enc 4, state 0, tid 68, use 4, grp 4, prior (n il) [Falcon] Error: assertion (false) failed at line 1083 in file Table.cpp
[7 Apr 2009 17:54]
Kevin Lewis
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/71557 3105 Kevin Lewis 2009-04-07 Bug#43961 & Bug#41661 - Table::insertIntoTree could fail during a Table::insert. This should not happen since Dbb::insertStub should have returned a record number that was free. Nobody else should have been messing with that slot in the RecordLeaf. The problem was in RecordLeaf::retireRecords. This function called RecordVersion::retire which then called expungeRecord. This makes the record number free to use again by any other thread. It did this with an exclusive lock on the RecordLeaf, but Table::insertIntoTree often does not get any lock on RecordLeaf when it calls RecordLeaf::store. So a free record number is reused in Table::insert before the slot has been set to NULL by RecordLeaf::retireRecords. That is why Table::insertIntoTree fails. It expects the slot to be NULL. Another problem fixed is that the first of the two Table::insert functions did not check the return value of insertIntoTree at all. This would have propagated the error further since there would be nothing in the RecordTree slot after the insert. Another problem fixed in RecordLeaf::retireRecords is with this statement; if (record && recordScavenge->canBeRetired(record)) The problem is with incrementing the 'count' integer. If it is zero after stepping through the RecordLeaf, then it is assumed that the RecordLeaf is empty and can be retired. But this 'if' statement gets the wrong result. If the RecordLeaf is full of newer records that cannot yet be retired, then this count will remain zero. The emptySections bitmap will be set for this RecordLeaf. And later, in Table::retireRecords, it will attempt to retire these sections. But finding records in them, it will just waste a lot of time while blocking all table access. I changed this code to be accurate in determining if the RecordLeaf is indeed empty before setting the bit in Table::emptySections. Record::retire and RecordVersion::retire now only retire records. The more thorough tests for whether a record can be retired is collected into RecordScavenge::canBeRetired. Also, instead of just setting the slot in RecordLeaf to NULL directly, I now use a COMPARE_EXCHANGE_POINTER() just like every other place where this location is changed. Then if it fails for any reason, we will not retire that record. One legitimate reason that this could fail is when this record is determined that it canBeRetired, but immediately after that, a client thread does a fetchForUpdate, adding a lockRecord.
[7 Apr 2009 18:01]
Kevin Lewis
Here is how this error could have happened with the code before this patch; * Scavenger thread; Calls RecordVersion::retire which calls expungeRecord, which releases the record number to be used again. * Client thread 1; Calls Table::insert( Transaction *, int, Field **, Value **), which calls insertIntotree. This fails since the slot is not currently NULL as expected. But this code did not check the return code so it assumes that insertIntoTree succeeded and goes on with the insert. * Scavenger thread; sets RecordLeaf::records[slot] to NULL; * Client thread 2; calls StorageInterface::rnd_next -> StorageDatabase::nextRow -> Table::fetch. The record should exist according to recordBitmap, but nothing is in the record tree. So this record number is read from the page. This is probably an old version of that record number, a recently deleted record that the gopher threads have not yet removed from the page. (This misstep is not even necessary, but it could happen, which can lead to other problems) * Client Thread 1; Something else went wrong with the insert. Maybe a duplicate conflict. An exception is thrown and caught in Table::insert. Another call to insertIntoTree is made to put NULL in the record tree slot, but the wrong record is there so it fails. But Table::insert does not check the return value here either! (This may lead to the following rollback, or even something else could have caused it. If this insert does not rollback, other issues could arise.) * Client Thread 1; Rollback; calls StorageInterface::rollback -> StorageConnection::rollbackVerb -> StorageConnection::savepointRollback -> StorageDatabase::savepointRollback -> Transaction::rollbackSavepoint -> RecordVersion::rollback(). The transaction has a pointer to the inserted record that really did not get into the record tree. Table::insertIntoTree fails for this record because it is not there. No way to recover so it asserts as in this bug.
[9 Apr 2009 12:03]
Philip Stoev
This still happens, however the code has been changed if (!insertIntoTree(priorRecord, recordToRollback, recordToRollback->recordNumber)) { if (priorRecord == NULL && priorState == recDeleted) return; // The store of this record into the record leaf failed. No way to recover. // While the base record is uncommitted, only that trensaction can change it. recordToRollback->printRecord("Table::rollbackRecord failed"); bool rollbackRecord_DamagedRecordTree = false; ASSERT(rollbackRecord_DamagedRecordTree); } and therefore the assertion is different.
[9 Apr 2009 13:07]
Vladislav Vaintroub
bool rollbackRecord_DamagedRecordTree = false; ASSERT(rollbackRecord_DamagedRecordTree); seems a little bit constructed. I think FATAL("damaged record tree"); could be used, does not require an extra bool variable and allows any text, not only C++
[9 Apr 2009 13:33]
Kevin Lewis
I was able to reproduce this in the debugger and am looking at it. At the top of Table::rollbackRecord) there are these lines; int priorState = recordToRollback->state; recordToRollback->state = recRollback; The curious thing is that priorState == recRollback. This means that recordToRollback has already been rolled back once before. So this record must somehow have been put on the transaction list twice.
[27 Apr 2009 13:43]
Kevin Lewis
On 27 Apr, 2009, 14:12, Hakan Kuecuekyilmaz reported duplicate bug 44491. Description: Running DBT2 on caneland with 20 warehouses and 192 hit Signal 6 with Table::rollbackRecord-insertIntoTree failed, priorState = The priorState did not print out due to an error in this new FATAL string.
[7 May 2009 11:23]
Olav Sandstå
With the last fix that includes printing of the priorState, this crash produced the following output: Table::rollbackRecord failed: 0xa5d94628 Id 947, enc 4, state 6, tid 66, use 1, grp 3, prior (nil) [Falcon] Error: Table::rollbackRecord-insertIntoTree failed, priorState =12 The constant 12 is representing the following record state: static const int recQueuedForDelete = 12; // end of chain for garbage collection
[3 Jun 2009 20:50]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/75562 2717 Kevin Lewis 2009-06-03 Bug#43961 & Bug#44223 Both of these bugs are caused by a record that gets queued for delete while still chained up to the transaction. Then during Transaction::rolback (44223) a record to rollback is queued for delete a second time. Or during Transaction::rollbackSavepoint (43961), the code assumes that this record on the transaction and savepoint is still the base record since it has Record::superceded=false, and tries to call insertIntoTree to rerplace it with its prior. But this record is not the base record either. This can happen in Table::update(Transaction * transaction, Record *orgRecord, Stream *stream); If this update replaces a lock record with an updated record and an exception occurred, it may or may not take the record off the transaction and the tree, but it would always queue the lock record for delete. This code has gone through some iterations lately. But in the most recent code, I was able to reporduce 44223. This patch cleans it up even more by distinguishing whether a record is actually inserted into the tree and added to the transaction. It undoes those actions only if they were done. Then if the update started with a lock record, that recordversion will remain on the tree with superceded=false and it will not be queued for delete. It correctly uses the 'wasLock' variable instead of the 'updated' or 'wasUpdated' flag.