Bug #43488 Crash in Table::fetchForUpdate (update conflict) when using LIMIT query
Submitted: 8 Mar 2009 21:22 Modified: 15 May 2009 17:03
Reporter: John Embretsen Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S1 (Critical)
Version:6.0.11-bzr OS:Any
Assigned to: Lars-Erik Bjørk CPU Architecture:Any
Tags: F_LIMIT, stress_tx

[8 Mar 2009 21:22] John Embretsen
Description:
During transactional stress testing of Falcon using 4 concurrent threads, a crash occurred when executing a query with LIMIT and FOR UPDATE.

Default settings (REPEATABLE-READ, falcon_consistent_read ON).
Debug build, Linux.

090308 21:57:20 [ERROR] /home/johnemb/dev/mysql/bzr-repos/mysql-6.0-falcon-team-jsandbox/sql/mysqld: Sort aborted
terminate called after throwing an instance of 'SQLError'
090308 21:57:20 - mysqld got signal 6 ;
(...)
thread_count=3
connection_count=3

(... <for stacktrace, see below> ...)

thd->query at 0xaa19718 = SELECT * FROM t1 WHERE `int1_unique` BETWEEN 981 + (CONNECTION_ID() MOD 15) AND 1030 ORDER BY `int1_unique` LIMIT 10 FOR UPDATE
thd->thread_id=1034
thd->killed=NOT_KILLED

------------

gdb backtrace:

#10 0xb7ef6612 in std::terminate () from /usr/lib/libstdc++.so.6
#11 0xb7ef674a in __cxa_throw () from /usr/lib/libstdc++.so.6
#12 0x08586f03 in Table::fetchForUpdate (this=0xb72fd648, transaction=0xb7058db8, source=0xada58168, usingIndex=true) at Table.cpp:3526
#13 0x085ec4da in IndexWalker::getValidatedRecord (this=0xb730fde8, recordId=1508, lockForUpdate=true) at IndexWalker.cpp:150
#14 0x08670ab6 in WalkIndex::getNext (this=0xb730fde8, lockForUpdate=true) at WalkIndex.cpp:76
#15 0x085704d6 in StorageDatabase::nextIndexed (this=0xb6f73158, storageTable=0xb72ff150, indexWalker=0xb730fde8, lockForUpdate=true)
    at StorageDatabase.cpp:487
#16 0x0857732e in StorageTable::nextIndexed (this=0xb72ff150, recordNumber=0, lockForUpdate=true) at StorageTable.cpp:169
#17 0x08567c2c in StorageInterface::index_next (this=0xa974088, buf=0xa974258 "��") at ha_falcon.cpp:1848
#18 0x08566adc in StorageInterface::read_range_first (this=0xa974088, start_key=0xa97411c, end_key=0xa97412c, eq_range_arg=false, sorted=true)
    at ha_falcon.cpp:1749
#19 0x0840186b in handler::multi_range_read_next (this=0xa974088, range_info=0xae4f8474) at handler.cc:4342
#20 0x08567914 in StorageInterface::multi_range_read_next (this=0xa974088, rangeInfo=0xae4f8474) at ha_falcon.cpp:1977
#21 0x083e1ae7 in QUICK_RANGE_SELECT::get_next (this=0xa936850) at opt_range.cc:8558
#22 0x083fb55d in rr_quick (info=0xa94ef7c) at records.cc:322
#23 0x0833de3a in join_init_read_record (tab=0xa94ef38) at sql_select.cc:17028
#24 0x0834173b in sub_select (join=0xa94a0f8, join_tab=0xa94ef38, end_of_records=false) at sql_select.cc:16222
#25 0x0834e228 in do_select (join=0xa94a0f8, fields=0xa912bc0, table=0x0, procedure=0x0) at sql_select.cc:15786
#26 0x08365213 in JOIN::exec (this=0xa94a0f8) at sql_select.cc:2881
#27 0x0835fd28 in mysql_select (thd=0xa911920, rref_pointer_array=0xa912c30, tables=0xaa19b50, wild_num=1, fields=@0xa912bc0, conds=0xaa1a320, 
    og_num=1, order=0xaa1a568, group=0x0, having=0x0, proc_param=0x0, select_options=2149337600, result=0xaa1a600, unit=0xa91289c, 
    select_lex=0xa912b2c) at sql_select.cc:3062
#28 0x0836550f in handle_select (thd=0xa911920, lex=0xa912840, result=0xaa1a600, setup_tables_done_option=0) at sql_select.cc:314
#29 0x082c9450 in execute_sqlcom_select (thd=0xa911920, all_tables=0xaa19b50) at sql_parse.cc:4768
#30 0x082cab0c in mysql_execute_command (thd=0xa911920) at sql_parse.cc:2069
#31 0x082d39f8 in mysql_parse (thd=0xa911920, 
    inBuf=0xaa19718 "SELECT * FROM t1 WHERE `int1_unique` BETWEEN 981 + (CONNECTION_ID() MOD 15) AND 1030 ORDER BY `int1_unique` LIMIT 10 FOR UPDAT---Type <return> to continue, or q <return> to quit--- 
E", length=127, found_semicolon=0xae4f9be8) at sql_parse.cc:5763
#32 0x082d457a in dispatch_command (command=COM_QUERY, thd=0xa911920, packet=0xa98ef19 "", packet_length=127) at sql_parse.cc:1009
#33 0x082d5b3e in do_command (thd=0xa911920) at sql_parse.cc:691
#34 0x082c2eb4 in handle_one_connection (arg=0xa911920) at sql_connect.cc:1146
#35 0xb7f3250f in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#36 0xb7d3a7ee in clone () from /lib/tls/i686/cmov/libc.so.6

--------------

Table.cpp, lines 3519-3526:

    case CommittedInvisible:
        // CommittedInvisible only happens for consistent read.

        ASSERT(IS_CONSISTENT_READ(transaction->isolationLevel));
        source->release(REC_HISTORY);
        Log::debug("Table::fetchForUpdate: Update Conflict: TransId=%d, RecordNumber=%d, Table %s.%s\n",
        transaction->transactionId, source->recordNumber, schemaName, name);
        throw SQLError(UPDATE_CONFLICT, "update conflict in table %s.%s", schemaName, name);

How to repeat:
See comments.
[8 Mar 2009 21:40] John Embretsen
On a related note, Bug#43447 (Crash when executing SELECT ... LIMIT n FOR UPDATE query) occurred when running the same test against InnoDB. That problem seemed to be caused by the MRR optimizer feature (workaround was to disable MRR). However, that does not seem to be related to this bug (crash occurs regardless of MRR options).
[9 Mar 2009 8:07] Kevin Lewis
An update conflict is a very common in Falcon when using consistent_read.  This exception is normally caught.  But in this call stack which uses IndexWalker::getValidatedRecord, it caused a crash.
[9 Mar 2009 9:18] Olav Sandstå
One comment to the code:

This SQLError is thrown just three lines after the assert that is hit in bug#41357. In that bug we get into this part of the switch statement due to operating on a deleted transaction object. Thus, it might that after fixing bug#41357 we will never end up in this situation again where the SQLError is thrown and not caught.

bug#41357 is most likely to occur in situations where we have multiple concurrent threads - just as in this test case.
[9 Mar 2009 9:47] Ann Harrison
It's quite likely that there should be a catch for update conflict in IndexWalker - Jim wrote it and he has yet to internalize that a select can get update conflicts.  (Nor have I for that matter).
[10 Mar 2009 8:31] 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/68732

3059 lars-erik.bjork@sun.com	2009-03-10
      This is a patch for Bug #43488
      Crash in Table::fetchForUpdate (update conflict) when using LIMIT query
      
      This crash was due to missing exception handling when calling fetchForUpdate
      when fetching records through the IndexWalker. The exception handling
      introduced in this patch is split in two parts. The first part does the 
      necessary cleanup in IndexWalker::getValidatedRecord and re-throws the 
      exception. The exception is re-caught in StorageDatabase::nextIndexed, 
      where we return the correct error.
      
      I have not included any test files for this patch, because it is not
      easily reproducible without a larger framework as described in the bug
      report.
      
      Modified file 'storage/falcon/IndexWalker.cpp'
      ----------------------------------------------
      Added try - catch logic, doing the necessary cleanup in the case
      of an exception. This implementation is based on the similar cases
      in StorageDatabase.cpp. After the cleanup has been done, we re-throw
      the exception, so that we can return the appropriate error in 
      StorageDatabase::nextIndexed
       
      Modified file 'storage/falcon/StorageDatabase.cpp'
      --------------------------------------------------
      Recatch the exception and return the appropriate error.
      modified:
        storage/falcon/IndexWalker.cpp
        storage/falcon/StorageDatabase.cpp
[10 Mar 2009 10:11] John Embretsen
I can confirm that with the committed patch applied I no longer see the crash with the same stress test, while it crashes without the patch.

Most likely the update conlicts result in the following error:

Error 1020 Record has changed since last read in table 't1'

which I do observe sometimes when executing the SELECT ... LIMIT ... FOR UPDATE queries. WorkLog#3715 http://forge.mysql.com/worklog/task.php?id=3715 indicates that this is the type of error the client sees when there is an update conflict.

Patch OK to push from my perspective :)
[10 Mar 2009 23:04] Kevin Lewis
Code is OK to push with the changes I suggested.
[16 Mar 2009 9:04] 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/69265

3060 lars-erik.bjork@sun.com	2009-03-16
      Small changes to patch for Bug #43488 Crash in Table::fetchForUpdate (update conflict) when using LIMIT query, based on Kevin's review comments
      modified:
        storage/falcon/IndexWalker.cpp
[2 Apr 2009 17:39] Bugs System
Pushed into 6.0.11-alpha (revid:hky@sun.com-20090402144811-yc5kp8g0rjnhz7vy) (version source revid:lars-erik.bjork@sun.com-20090316090642-uwkwrdmeaa8bmgmm) (merge vers: 6.0.11-alpha) (pib:6)
[15 May 2009 17:03] MC Brown
A note has been added to the 6.0.11 changelog: 

Executing a LIMIT ... FOR UPDATE statement on a Falcon table when using transactions with concurrent threads could cause a crash because the record information cannot be accessed correctly.