| Bug #41831 | Error: assertion (record->state != recLock) failed at line 1999 in file Table.cp | ||
|---|---|---|---|
| Submitted: | 2 Jan 2009 20:44 | Modified: | 15 May 2009 12:56 |
| Reporter: | Philip Stoev | Email Updates: | |
| Status: | Closed | 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_SCAVENGER | ||
[7 Jan 2009 18:35]
Kevin Lewis
Philip, Please be aware that the new scavenger code will move this assert to;
+void RecordLeaf::pruneRecords (Table *table, int base, RecordScavenge *recordScavenge)
{
. . .
+ ASSERT(oldestVisible->state != recLock);
Since the algorithm is different, it is possible that the conditions that lead to this strange bug are no longer around. Those changes will be pushed to falcon-team shortly. See Bug#34893, Bug#36700, Bug#40342, Bug#40801
[8 Jan 2009 5:31]
Kevin Lewis
I was able to reproduce this bug with RQG and the new assert mentioned previously with the new scavenger code.
The records being pruned are in a strange state.
The base record is state=recDeleted,
next prior is recLocked in the same transaction,
next prior is a record version from a previous transaction.
The delete should have used the lock record instead of creating its own record version.
+ data {record=0x00000000}
useCount 1
recordNumber 5091
size 88
generation 1
highWater -13108
encoding 0
state 1 {recDeleted}
active 1
- [RecordVersion]
virtualOffset 2422945
+ transaction 0x00000000
+ nextInTrans 0x00000000
+ prevInTrans 0x00000000
transactionId 8327
savePointId 4
superceded false
- priorVersion
+ data {record=0x00000000 }
useCount 2
recordNumber 5091
size 88
generation 1
highWater -13108
encoding 0
state 4 {recLocked}
active 0
- [RecordVersion]
virtualOffset 0
+ transaction 0x00000000
+ nextInTrans 0x00000000
+ prevInTrans 0x00000000
transactionId 8327
savePointId 0
superceded true
- priorVersion 0x068333a0
+ data {record=0x06833778 }
useCount 1
+ format 0x0418ebc8
recordNumber 5091
size 101
generation 1
highWater 2
encoding 4
state 0
active 0
- [RecordVersion]
+ priorVersion 0x00000000
virtualOffset 2420023
+ transaction 0x00000000
+ nextInTrans 0x00000000
+ prevInTrans 0x00000000
transactionId 8321
savePointId 0 int
superceded false
[15 Jan 2009 4:33]
Kevin Lewis
Move to patch pending. I tested this code quite a bit. falcon_record_cache_memory_leak2 ran 25 times straight. The trigger somehow failed to send a message to commits@lists.mysql.com today, so here is the changeset info revno: 2959 revision-id: klewis@mysql.com-20090114223344-og8t9pw03ckyexdw committer: Kevin Lewis <klewis@mysql.com> branch nick: mysql-6.0-falcon-team timestamp: Wed 2009-01-14 16:33:44 -0600 message: Bug#42080, Bug#41831 In both of these bugs, the scavenger was pruning records that it should not have. The record version chosen to start pruning is returned from RecordScavenge::inventoryRecord(). This function is improved so that only the oldest visible record is returned. In addition, Recordversion::committedbefore() is added to simplify the code and read RecordVersion::transaction only once since it can be set to null at any time.
[15 Jan 2009 4:36]
Kevin Lewis
Found this message in Bug#42080; 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/63294 2959 Kevin Lewis 2009-01-14 Bug#42080, Bug#41831 In both of these bugs, the scavenger was pruning records that it should not have. The record version chosen to start pruning is returned from RecordScavenge::inventoryRecord(). This function is improved so that only the oldest visible record is returned. In addition, Recordversion::committedbefore() is added to simplify the code and read RecordVersion::transaction only once since it can be set to null at any time.
[28 Jan 2009 7:24]
Vladislav Vaintroub
Assertion has been seen again with the latest Falcon-team, yet on another location (RecordLeaf, line 143) Following RQG command was used to crash: perl runall.pl --mysqld=--falcon-page-size=8K --rows=100 --threads=16 --mask=59 --queries=1000000 --duration=300 --basedir=G:\bzr\mysql-6.0-falcon-team --engine=Falcon --grammar=conf/combinations.yy --gendata=conf/combinations.zz --reporter=Deadlock,ErrorLog,Backtrace,Recovery --mysqld=--loose-falcon-lock-wait-timeout=1 --mysqld=--log-output=none Callstack: mysqld.exe!Error::error(const char * string=0x0000000140afd238, ...) Line 73 C++ mysqld.exe!Error::assertionFailed(const char * text=0x0000000140b28440, const char * fileName=0x0000000140b28428, int line=0x0000008f) Line 79 C++ > mysqld.exe!RecordLeaf::pruneRecords(Table * table=0x0000000004dbeb08, int base=0x00000001, RecordScavenge * recordScavenge=0x0000000005d9f7c0) Line 143 + 0x2a bytes C++ mysqld.exe!RecordGroup::pruneRecords(Table * table=0x0000000004dbeb08, int base=0x00000000, RecordScavenge * recordScavenge=0x0000000005d9f7c0) Line 123 C++ mysqld.exe!Table::pruneRecords(RecordScavenge * recordScavenge=0x0000000005d9f7c0) Line 1907 + 0x37 bytes C++ mysqld.exe!Database::pruneRecords(RecordScavenge * recordScavenge=0x0000000005d9f7c0) Line 1855 + 0x12 bytes C++ mysqld.exe!Database::scavengeRecords() Line 1806 C++ mysqld.exe!Database::scavenge() Line 1771 C++ mysqld.exe!Database::scavengerThreadMain() Line 1932 C++ mysqld.exe!Database::scavengerThreadMain(void * database=0x0000000004c10c28) Line 1920 C++ mysqld.exe!Thread::thread() Line 168 C++ mysqld.exe!Thread::thread(void * parameter=0x0000000004e2b0e8) Line 146 C++
[30 Jan 2009 5:35]
Kevin Lewis
Putting this bug back to patch queued because the other assert was fixed. The current assert is still happenning and is tracked by Bug#42340 : Falcon assertion (oldestVisible->state != recLock) in RecordLeaf::pruneRecords, line 143
[13 Feb 2009 7:24]
Bugs System
Pushed into 6.0.10-alpha (revid:alik@sun.com-20090211182317-uagkyj01fk30p1f8) (version source revid:klewis@mysql.com-20090114223344-og8t9pw03ckyexdw) (merge vers: 6.0.10-alpha) (pib:6)
[15 May 2009 12:56]
MC Brown
An entry has been added to the 6.0.10 changelog: The Falcon storage engine has been updated to incorporate new code for the built-in scavenger service, which handles the caching of records in memory. This fixes a number of different issues related to the visibility of different records during certain operations and improves the memory usage.
Description: When executing a simple random workload, Falcon asserted as follows: #0 0x000000315b00c216 in pthread_kill () from /lib64/libpthread.so.0 #1 0x00000000006563de in handle_segfault (sig=6) at mysqld.cc:2671 #2 <signal handler called> #3 0x000000315b00efab in raise () from /lib64/libpthread.so.0 #4 0x00000000008a6d88 in Error::debugBreak () at Error.cpp:94 #5 Error::error (string=<value optimized out>) at Error.cpp:71 #6 0x0000000000861844 in Table::expungeRecordVersions (this=0x7fa9dd725db0, record=0x8cb1688, recordScavenge=0x7fa9d1bf5e30) at Table.cpp:1999 #7 0x00000000008d635c in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=<value optimized out>) at RecordVersion.cpp:208 #8 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #9 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #10 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #11 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #12 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #13 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #14 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #15 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #16 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #17 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #18 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #19 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #20 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #21 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #22 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #23 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #24 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #25 0x00000000008d6345 in RecordVersion::scavenge (this=0xffffffffffffffff, recordScavenge=0x7fa9d1bf5e30, lockType=6) at RecordVersion.cpp:227 #26 0x00000000008d2eac in RecordLeaf::retireRecords (this=<value optimized out>, table=0x7fa9dd725db0, base=0, recordScavenge=0x7fa9d1bf5e30) at RecordLeaf.cpp:173 #27 0x000000000093506c in RecordGroup::retireRecords (this=<value optimized out>, table=0x7fa9dd725db0, base=<value optimized out>, recordScavenge=0x7fa9d1bf5e30) at RecordGroup.cpp:124 #28 0x000000000085e053 in Table::retireRecords (this=0x7fa9dd725db0, recordScavenge=0x7fa9d1bf5e30) at Table.cpp:1885 #29 0x000000000089803b in Database::retireRecords (this=0x7fa9dd5b5bb8, forced=false) at Database.cpp:1820 #30 0x00000000008982d2 in Database::scavenge (this=0x7fa9dd5b5bb8) at Database.cpp:1740 #31 0x00000000008e2346 in Scavenger::scavenge (this=<value optimized out>) at Scavenger.cpp:58 #32 Scavenger::execute (this=0x7fa9dd3bddb0, scheduler=0x7fa9dd3bdcd0) at Scavenger.cpp:68 #33 0x00000000008e387c in Scheduler::schedule (this=0x7fa9dd3bdcd0) at Scheduler.cpp:137 #34 0x000000000086c153 in Thread::thread (this=0x7fa9dd3c7d68) at Thread.cpp:167 #35 0x000000000086c321 in Thread::thread (parameter=0x355a) at Thread.cpp:146 #36 0x000000315b0073da in start_thread () from /lib64/libpthread.so.0 #37 0x000000315a4e627d in clone () from /lib64/libc.so.6 (gdb) list 1994 return false; 1995 } 1996 1997 void Table::expungeRecordVersions(RecordVersion *record, RecordScavenge *recordScavenge) 1998 { 1999 ASSERT(record->state != recLock); 2000 2001 Record *prior = record->clearPriorVersion(); 2002 2003 if (recordScavenge) (gdb) print record->state $1 = 4 '\004' How to repeat: If this is repeatable, a test case will be provided.