Bug #38569 Falcon assertion in SRLUpdateIndex::thaw : type == srlUpdateIndex
Submitted: 5 Aug 2008 12:01 Modified: 13 Dec 2008 9:04
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S1 (Critical)
Version:6.0-falcon OS:Any
Assigned to: Christopher Powers CPU Architecture:Any
Tags: F_CHILL THAW

[5 Aug 2008 12:01] Philip Stoev
Description:
When executing an INSERT/UPDATE workload under chill_threshold=4K, Falcon asserted as follows:

#8  0x0857c025 in Error::error (string=0x8965978 "assertion (%s) failed at line %d in file %s\n") at Error.cpp:71
#9  0x0857c0cf in Error::assertionFailed (text=0x89702c7 "type == srlUpdateIndex", fileName=0x8970185 "SRLUpdateIndex.cpp", line=259) at Error.cpp:78
#10 0x085f6249 in SRLUpdateIndex::thaw (this=0xa7e44d08, deferredIndex=0xb71a6940) at SRLUpdateIndex.cpp:259
#11 0x0853ef50 in Transaction::thaw (this=0xb718b858, deferredIndex=0xb71a6940) at Transaction.cpp:584
#12 0x08575cd4 in DeferredIndex::scanIndex (this=0xb71a6940, lowKey=0x0, highKey=0xb73ced44, searchFlags=4, bitmap=0xb7146e00) at DeferredIndex.cpp:794
#13 0x0858bba4 in Index::scanIndex (this=0xb7064008, lowKey=0x0, highKey=0xb73ced44, searchFlags=4, transaction=0xb7187078, bitmap=0xb7146e00)
    at Index.cpp:446
#14 0x0851ab5d in StorageDatabase::indexScan (this=0xb6ffe130, index=0xb7064008, lower=0x0, upper=0xb73ced40, searchFlags=4, storageConnection=0xb718ca90,
    bitmap=0xb7146e00) at StorageDatabase.cpp:818
#15 0x08521cfd in StorageTable::indexScan (this=0xb73cc2c8, indexOrder=0) at StorageTable.cpp:224
#16 0x08513abe in StorageInterface::read_range_first (this=0xadda368, start_key=0x0, end_key=0xadda40c, eq_range_arg=false, sorted=false)
    at ha_falcon.cpp:1544
#17 0x083ce5fa in handler::multi_range_read_next (this=0xadda368, range_info=0xa7e45170) at handler.cc:4258
#18 0x083aeeef in QUICK_RANGE_SELECT::get_next (this=0xae41418) at opt_range.cc:8518
#19 0x083c8897 in rr_quick (info=0xa7e4533c) at records.cc:298
#20 0x0835fc35 in mysql_update (thd=0xb7472f58, table_list=0xae19318, fields=@0xb74743f0, values=@0xb7474620, conds=0xae199c0, order_num=0, order=0x0,
    limit=18446744073709551615, handle_duplicates=DUP_ERROR, ignore=false) at sql_update.cc:573
#21 0x082bf817 in mysql_execute_command (thd=0xb7472f58) at sql_parse.cc:2846
#22 0x082c63e1 in mysql_parse (thd=0xb7472f58, inBuf=0xae18ff0 "UPDATE E AS X SET `int_nokey` = 134 WHERE X . `int_key` < 238", length=61,
    found_semicolon=0xa7e46270) at sql_parse.cc:5809
#23 0x082c6e55 in dispatch_command (command=COM_QUERY, thd=0xb7472f58, packet=0xb7475241 "UPDATE E AS X SET `int_nokey` = 134 WHERE X . `int_key` < 238",
    packet_length=61) at sql_parse.cc:1050
#24 0x082c8145 in do_command (thd=0xb7472f58) at sql_parse.cc:723
#25 0x082b5e23 in handle_one_connection (arg=0xb7472f58) at sql_connect.cc:1153
#26 0x0057d32f in start_thread () from /lib/libpthread.so.0
#27 0x0049a27e in clone () from /lib/libc.so.6

The assertion is here:

(gdb) list
254             ASSERT(control->inputEnd <= window->bufferEnd);
255
256             // Read the SerialLogRecord type and header
257
258             UCHAR type = getInt();
259             ASSERT(type == srlUpdateIndex); <<<<<<<<<<<<<< HERE
260             read();         // this read() is also in control->nextRecord() below.
261
262             while (virtualOffset < deferredIndex->virtualOffsetAtEnd)
263                     {

(gdb) print type
$2 = 21 '\025'

21 is the code for type srlIndexPage

How to repeat:
If this happens again, a test case will be provided.
[5 Aug 2008 12:04] Philip Stoev
To reproduce this bug, please clone the mysql-test-extra-6.0 repository and execute

$ cd mysql-test-extra-6.0/mysqltest/gentest
$ perl runall.pl \
  --basedir=/path/to/6.0-falcon/ \
  --engine=falcon \
  --grammar=conf/chill_thaw.yy \
  --threads=20 --queries=100000 \
  --mysqld=--falcon_debug_mask=7167 \
  --mysqld=--falcon_index_chill_threshold=4K \
  --mysqld=--falcon_record_chill_threshold=4K

The crash should happen within less than a mintute, after a few dozen chill/thaw operations.

During the Falcon Boston meeting, it was agreed that 4K is an acceptable value for those parameters, that is why I am testing with it. Values at least up to 32K will also produce crashes. The required grammar file is part of the mysql-test-extra-6.0 repository and does not have to be obtained separately. If the chill options are set to their default values, no crash occurs.
[19 Aug 2008 20:53] Kevin Lewis
Related to falcon_index_chill_threshold=4K
[24 Oct 2008 5:09] 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/56961

2880 Christopher Powers	2008-10-24
      Bug#36631,"Assertion in SerialLogControl::nextRecord"
      Bug#38541,"Falcon RecordVersion::thaw assertion """"bytesRestored > 0 || data.record == NULL"""
      Bug#38567,"Falcon crash in  Record::getEncodedRecord at Record.cpp:743"
      Bug#38569,"Falcon assertion in SRLUpdateIndex::thaw : type == srlUpdateIndex"
      Bug#39694,"Crash in StorageTable::setRecord during falcon_chill_thaw test"
      Bug#39695,"Crash in SRLUpdateRecords::thaw during falcon_chill_thaw test"
      Bug#39696,"Assertion in Table.cpp (dup->state == recDeleted) fails during falcon_chill_thaw"
      
      Fix 1 of 3 for chill/thaw bugs.
      
      Modified Record::hasRecord() to thaw if necessary, removed redundant record thaws, added exception handling
[24 Oct 2008 5:38] 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/56962

2881 Christopher Powers	2008-10-24
      Bug#36631,"Assertion in SerialLogControl::nextRecord"
      Bug#38541,"Falcon RecordVersion::thaw assertion """"bytesRestored > 0 || data.record == NULL"""
      Bug#38567,"Falcon crash in  Record::getEncodedRecord at Record.cpp:743"
      Bug#38569,"Falcon assertion in SRLUpdateIndex::thaw : type == srlUpdateIndex"
      Bug#39694,"Crash in StorageTable::setRecord during falcon_chill_thaw test"
      Bug#39695,"Crash in SRLUpdateRecords::thaw during falcon_chill_thaw test"
      Bug#39696,"Assertion in Table.cpp (dup->state == recDeleted) fails during falcon_chill_thaw"
      
      Fix 2 of 3 for chill/thaw bugs.
      
      Synchronized record thaw operations using a pool of sync objects in the associated table.
      Record chill operations do not need to be synchronized because chills are performed in one place, and only by the active Transaction.
[26 Oct 2008 15:54] Kevin Lewis
Two patches approved to problems with concurent thaws.
1) enhance hasRecord to thaw when needed.
2) serialize thaws with a hash table of SyncOjects.
[28 Oct 2008 8:09] Bugs System
Pushed into 6.0.8-alpha  (revid:cpowers@mysql.com-20081024053538-6y1ma8lydl93oxza) (version source revid:alik@mysql.com-20081028074021-o49ijs3x4pxj1gbm) (pib:5)
[11 Nov 2008 22:37] 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/58507

2908 Christopher Powers	2008-11-11
      Bug#38569, "Falcon assertion in SRLUpdateIndex::thaw : type == srlUpdateIndex"
      
      The fix for Bug#39696, "Assertion in Table.cpp (dup->state == recDeleted)"
      exposed another problem with chill/thaw for deferred indexes.
      
      Changed SRLUpdateIndex::append() to advance past srlVersion records written
      at the top of each block within a window.
      
      Also removed a gap in mutex protection in the loop that reconstructs the
      DeferredIndex from multiple serial log records.
[20 Nov 2008 12:55] Bugs System
Pushed into 6.0.9-alpha  (revid:cpowers@mysql.com-20081111223327-wwdaexuslbhub3ec) (version source revid:cpowers@mysql.com-20081111223327-wwdaexuslbhub3ec) (pib:5)
[13 Dec 2008 9:04] MC Brown
No documentation needed (internal change only)