| Bug #44911 | Falcon crashes with Error: Committed non-deleted record has no data buffer. | ||
|---|---|---|---|
| Submitted: | 15 May 2009 21:13 | Modified: | 26 May 2010 17:47 |
| Reporter: | Olav Sandstå | Email Updates: | |
| Status: | Unsupported | Impact on me: | |
| Category: | MySQL Server: Falcon storage engine | Severity: | S2 (Serious) |
| Version: | 6.0.12-alpha | OS: | Any |
| Assigned to: | Kevin Lewis | ||
| Triage: | Triaged: D1 (Critical) | ||
[15 May 2009 21:15]
Olav Sandstå
Setting to verified based on seeing it several times in pushbuild. Possible workaround: do not play with the chill threshold.
[15 May 2009 21:16]
Olav Sandstå
Also seen on Windows so believe this is not a Linux-only problem.
[18 May 2009 10:10]
Olav Sandstå
This crash has also happened several times when running the falcon_bug_34890 test using the latest source from mysql-6.0-falcon-team.
[18 May 2009 17:29]
Kevin Lewis
This FATAL message was added recently, (after 6.0.11) because this condition did not make sense. I figured that if it occurred, it should be understood. So now it is occurring, and I will try to understand why it happens. The previous action was to return NULL from fetchForUpdate, which has the effect of saying that this record number is not visible to the viewing transaction. If that is the correct action to take, this can easily be fixed.
[26 May 2009 9:17]
Olav Sandstå
With the extra information added by Kevin's latest patch the output when this crash occurs is now:
[Falcon] Error: Committed non-deleted record has no data buffer. state=4, useCount=3, virtualOffset=0
where state=4 is (from Record.h):
static const int recLock = 4; // this is a "record lock" and not a record
From the core file the record version object has the following information:
(dbx) print -r *rv
*rv = {
RecordVersion::Record::data = {
RecordVersion::Record::record = (nil)
}
RecordVersion::Record::generation = 1ULL
RecordVersion::Record::format = 0x18ab390
RecordVersion::Record::useCount = 3
RecordVersion::Record::recordNumber = 1137
RecordVersion::Record::size = 96
RecordVersion::Record::highWater = -13108
RecordVersion::Record::encoding = '\0'
RecordVersion::Record::state = '\004'
RecordVersion::priorVersion = 0x3817ba8
RecordVersion::virtualOffset = 0
RecordVersion::nextInTrans = 0x3819ba8
RecordVersion::prevInTrans = 0x3819aa8
RecordVersion::savePointId = 0
RecordVersion::superceded = true
RecordVersion::transactionState = 0x45d8808
}
[26 May 2009 18:33]
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/74976 2713 Kevin Lewis 2009-05-26 Bug#44911 - Suppose a call to fetchForUpdate is called for a base lockRecord returned from Table::fetch, but before it is evaluated, the lockRecord is superceded by an update record and the transaction is committed. FetchForUpdate will need to re-fetch the new committed record as if getRelativeState() had returned WasActive. But getRelativeState() returned CommittedVisible. That would have caused this FATAL condition that a "Committed non-deleted record has no data buffer". So a check for (source->state == recLock) needs to be done in order to re-fetch the base record. A lockRecord can still be linked to a transaction after the commit if it was updated at a higher savepoint. But they are always superceded with newer records. Regular lockRecords are unlinked fro transaction during the commit in the call to Transaction::releaseRecordLocks().
[2 Jun 2009 14:41]
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/75470 2713 Kevin Lewis 2009-06-02 Bug#44911 - Suppose a call to fetchForUpdate is called for a base lockRecord returned from Table::fetch, but before it is evaluated, the lockRecord is superceded by an update record and the transaction is committed. FetchForUpdate will need to re-fetch the new committed record as if getRelativeState() had returned WasActive. But getRelativeState() returned CommittedVisible. That would have caused this FATAL condition that a "Committed non-deleted record has no data buffer". So a check for (source->state == recLock) needs to be done in order to re-fetch the base record. A lockRecord can still be linked to a transaction after the commit if it was updated at a higher savepoint. But they are always superceded with newer records. Regular lockRecords are unlinked from transactions during the commit in the call to Transaction::releaseRecordLocks(). So if a lock record is the base record and the transaction turns out to be committed, then the transaction must have been committed after the fetch. And it would only be CommittedVisible if the isolation was ReadCommitted or WriteCommitted. It would not happen with ConsistentRead.
[3 Jun 2009 21:01]
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/75565 2718 Kevin Lewis 2009-06-03 Bug#44911 - More follow-on changes. This assures that there will not be a infinite loop in the case where a lock record is returned from Table::fetch and the transaction becomes CommittedVisible soon after. This should only occur once. The next time, it has to be a different lock record. If the same record is read again, something is fataly wrong. It happened once while I was making some changes for 43344 because of a mistake. So instead of looping infinitely reading the same record, this patch will issue a fatal error.
Description: When running the RQG test falcon_chill_thaw Falcon crashed with the following error written: [Falcon] Error: Committed non-deleted record has no data buffer. The call stack looks like: Program terminated with signal 6, Aborted. #0 0x00251402 in __kernel_vsyscall () #0 0x00251402 in __kernel_vsyscall () #1 0x0089f067 in pthread_kill () from /lib/libpthread.so.0 #2 0x08836f0e in my_write_core (sig=6) at stacktrace.c:309 #3 0x082c21de in handle_segfault (sig=6) at mysqld.cc:2710 #4 <signal handler called> #5 0x00251402 in __kernel_vsyscall () #6 0x008a2181 in raise () from /lib/libpthread.so.0 #7 0x08569bd4 in Error::debugBreak () at Error.cpp:94 #8 0x08569c50 in Error::error ( string=0x89f3e18 "Committed non-deleted record has no data buffer.\n") at Error.cpp:71 #9 0x0858c833 in Table::fetchForUpdate (this=0xb73f2e58, transaction=0xb71e8178, source=0xae3cce08, usingIndex=false) at Table.cpp:3538 #10 0x08577114 in StorageDatabase::nextRow (this=0xb706d158, storageTable=0xb61ed010, recordNumber=3, lockForUpdate=true) at StorageDatabase.cpp:295 #11 0x0857d4e6 in StorageTable::next (this=0xb61ed010, recordNumber=3, lockForUpdate=true) at StorageTable.cpp:161 #12 0x0855dace in StorageInterface::rnd_next (this=0xb2f2db8, buf=0xb2f2f90 "") at ha_falcon.cpp:654 #13 0x083ff77f in rr_sequential (info=0xa6f68ed8) at records.cc:390 #14 0x0838ffe1 in mysql_update (thd=0xa633c748, table_list=0xb2e68d0, fields=@0xa633db2c, values=@0xa633dd60, conds=0xb2e71e8, order_num=0, order=0x0, limit=18446744073709551612, handle_duplicates=DUP_ERROR, ignore=false) at sql_update.cc:584 #15 0x082d5ef5 in mysql_execute_command (thd=0xa633c748) at sql_parse.cc:3127 #16 0x082dc117 in mysql_parse (thd=0xa633c748, inBuf=0xb2e65d0 "UPDATE `E` AS X SET `date_key` = 'qhqhbxbxwlwlboboxbxbtmtmtftfdbdbdkdkbrbrmwmwononpkpknynyhnhnddddswswvjvjhuhuqkqkirirwjwjopopububnonoqrqrtetefpfpododwpwpgbgbococacacsgsgkpkplglgtptpwbwbnanajrjrpupukg"..., length=317, found_semicolon=0xa6f69e80) at sql_parse.cc:5964 #17 0x082dd299 in dispatch_command (command=COM_QUERY, thd=0xa633c748, packet=0xa6343bc1 "UPDATE `E` AS X SET `date_key` = 'qhqhbxbxwlwlboboxbxbtmtmtftfdbdbdkdkbrbrmwmwononpkpknynyhnhnddddswswvjvjhuhuqkqkirirwjwjopopububnonoqrqrtetefpfpododwpwpgbgbococacacsgsgkpkplglgtptpwbwbnanajrjrpupukg"..., packet_length=317) at sql_parse.cc:1049 #18 0x082de52a in do_command (thd=0xa633c748) at sql_parse.cc:731 #19 0x082caecf in handle_one_connection (arg=0xa633c748) at sql_connect.cc:1146 #20 0x0089a45b in start_thread () from /lib/libpthread.so.0 #21 0x007f1c4e in clone () from /lib/libc.so.6 The code where this happens is the following part of Table::fetchForUpdate(): case CommittedVisible: { if (source->state == recDeleted) { source->release(REC_HISTORY); return NULL; } if (!source->hasRecord()) FATAL("Committed non-deleted record has no data buffer.\n"); How to repeat: Seen a few times after having run falcon_chill_thaw.