Bug #37056 Falcon crashes in IndexRootPage::addIndexEntry
Submitted: 29 May 2008 7:15 Modified: 15 May 2009 14:11
Reporter: Allan Packer Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S1 (Critical)
Version:6.0.5-alpha-pb87 OS:Solaris (Solaris Express Community Edition snv_88 X86)
Assigned to: Vladislav Vaintroub CPU Architecture:Any
Tags: crash, create index, F_INDEX, falcon, page-size-2K, split-page

[29 May 2008 7:15] Allan Packer
Description:
Falcon crashed while creating indexes on a large table.  Here is the stacktrace:

             libc.so.1`_lwp_kill+0xa
             libc.so.1`raise+0x19
             mysqld`Error::error(char const*, ...)+0xe1
mysqld`IndexRootPage::addIndexEntry(Dbb*, int, IndexKey*, int, unsigned int)+0x28f
mysqld`IndexRootPage::indexMerge(Dbb*, int, SRLUpdateIndex*, unsigned int)+0x542
             mysqld`SRLUpdateIndex::commit()+0xc8
             mysqld`SerialLogTransaction::commit()+0xd8
             mysqld`SerialLogTransaction::doAction()+0xaa
             mysqld`Gopher::gopherThread()+0x184
             mysqld`Thread::thread()+0xda
             mysqld`Thread::thread(void*)+0x11
             libc.so.1`_thr_setup+0x89
             libc.so.1`_lwp_start

How to repeat:
This will not be easy to reproduce since the alter index ran for over 15 hours before crashing.

I can provide access to the test environment.
[29 May 2008 7:17] Hakan Küçükyılmaz
Allan,

can you please provide us with the data set to reproduce this crash? Can you also try on a Linux system, too?
[4 Jun 2008 17:08] Kevin Lewis
Hakan, Please keep trying to reproduce this bug by trying to get the data from Allan.  Maybe you can re-generate this database from scratch.
[26 Sep 2008 3:11] Hakan Küçükyılmaz
Kelly,

I am assigning this bug to you, as you are working on it already.
[13 Feb 2009 14:09] Philip Stoev
Recovery will also fail with the same assertion once it has crashed with it.
[18 Feb 2009 12:29] Kevin Lewis
Allan Packer saw this again recently with a large load.
See also Bug#40373.
A quick fix may be to increase the number of attempts.  But a deterministic solution is needed for splitting pages.
[7 Mar 2009 9:46] 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/68578

3050 Vladislav Vaintroub	2009-03-07
      Bug #37056 Falcon crashes in IndexRootPage::addIndexEntry
      The problem occurs during the split of an index page.
      
      Prior to the patch, splitIndexPage forgot to insert the index key if
      page was split in the middle. This was fixed by retrying the split/addNode
      up to 10 times. However, in concurrent situations retrying 10 times is not
      sufficient as pages can be continuiously filled up by concurrent threads.
      
      The fix is to ensure that splitIndexPage always adds index value to one of
      the two pages involved in split. This way no looping/retry is required  and
      assertion can be removed.
[7 Mar 2009 14:22] Kevin Lewis
Code looks OK.  The assert that we have looped more than 10 times cannot occur any more because the assert is missing now and we do not loop.  The indexKey is inserted while splitting the page in both splitIndexPageEnd and splitIndexPageMiddle.  So there is no reason to loop back around.  All pages involved are currently locked at the same time during the split so the addNode() can always be done now during the split.  Before Falcon had a serial log, it was important to loop around.
[16 Mar 2009 12:42] Kevin Lewis
After the patch was tried, Vlad saw a different sort of bug.  The patch is not pushed yet due to further analysis.
[14 Apr 2009 17:25] 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/72043

3122 Vladislav Vaintroub	2009-04-14 [merge]
      Bug#37056: 
      here is the patch that causes crashes . Provided for documentation purposes
[14 Apr 2009 17:27] Vladislav Vaintroub
After aypplying the patch to the latest Falcon code, the crash introduced by the patch looks like:

 	
mysqld.exe!Error::error(const char * string=0x00000001409c1428, ...)  Line 73	C++
 	mysqld.exe!Error::assertionFailed(const char * text=0x00000001409f0848, const char * fileName=0x00000001409f0868, int line=109)  Line 79	C++
>	mysqld.exe!IndexNode::parseNode(Btn * indexNode=0x0000000003123414)  Line 109 + 0x30 bytes	C++
 	mysqld.exe!IndexNode::getNext(void * end=0x0000000003123434)  Line 133	C++
 	mysqld.exe!IndexPage::findNodeInLeaf(IndexKey * indexKey=0x00000000076b6750, IndexKey * foundKey=0x00000000076b3a80)  Line 228	C++
 	mysqld.exe!IndexRootPage::scanIndex(Dbb * dbb=0x0000000002942090, int indexId=1, int rootPage=10, IndexKey * lowKey=0x00000000076b6750, IndexKey * highKey=0x00000000076b6750, int searchFlags=0, unsigned int transId=0, Bitmap * bitmap=0x00000000076b6708)  Line 356 + 0x1a bytes	C++
 	mysqld.exe!Index::scanIndex(IndexKey * lowKey=0x00000000076b6750, IndexKey * highKey=0x00000000076b6750, int searchFlags=0, Transaction * transaction=0x0000000000000000, Bitmap * bitmap=0x00000000076b6708)  Line 578	C++
 	mysqld.exe!Table::checkUniqueIndex(Index * index=0x0000000002b55ed8, Transaction * transaction=0x0000000003522ac8, RecordVersion * record=0x0000000005a8f628, Sync * sync=0x00000000076b9278)  Line 2532	C++
 	mysqld.exe!Table::insertIndexes(Transaction * transaction=0x0000000003522ac8, RecordVersion * record=0x0000000005a8f628)  Line 1314 + 0x2f bytes	C++
 	mysqld.exe!Table::insert(Transaction * transaction=0x0000000003522ac8, int count=11, Nfs::Field * * fieldVector=0x0000000002b877c0, Value * * values=0x0000000002b8c528)  Line 405	C++
 	mysqld.exe!NInsert::evalStatement(Nfs::Statement * statement=0x0000000002b8e720)  Line 144	C++
 	mysqld.exe!Nfs::Statement::start(NNode * node=0x0000000002b870a0)  Line 492 + 0x15 bytes	C++
 	mysqld.exe!PreparedStatement::executeUpdate()  Line 87	C++
 	mysqld.exe!Nfs::Field::save()  Line 304	C++
 	mysqld.exe!Table::save()  Line 300	C++
 	mysqld.exe!Nfs::Statement::createTable(Syntax * syntax=0x0000000002b52a08)  Line 228	C++
 	mysqld.exe!Nfs::Statement::upgradeTable(Syntax * syntax=0x0000000002b52a08)  Line 1202	C++
 	mysqld.exe!Nfs::Statement::executeDDL()  Line 745	C++
 	mysqld.exe!Nfs::Statement::execute(const char * sqlString=0x00000000076ba760, bool isQuery=false)  Line 2730	C++
 	mysqld.exe!Nfs::Statement::execute(const char * sqlString=0x00000000076ba760)  Line 163	C++
 	mysqld.exe!StorageDatabase::createTable(StorageConnection * storageConnection=0x0000000002b90088, const char * tableName=0x0000000002b8b77c, const char * schemaName=0x0000000002b9005c, const char * sql=0x00000000076ba760, __int64 autoIncrementValue=0)  Line 205	C++
 	mysqld.exe!StorageTableShare::create(StorageConnection * storageConnection=0x0000000002b90088, const char * sql=0x00000000076ba760, __int64 autoIncrementValue=0)  Line 212 + 0x6c bytes	C++
 	mysqld.exe!StorageTable::create(const char * sql=0x00000000076ba760, __int64 autoIncrementValue=0)  Line 77	C++
 	mysqld.exe!StorageInterface::create(const char * mySqlName=0x00000000076bbcf0, TABLE * form=0x00000000076bac70, st_ha_create_information * info=0x00000000076bc880)  Line 908 + 0x39 bytes	C++
 	mysqld.exe!handler::ha_create(const char * name=0x00000000076bbcf0, TABLE * form=0x00000000076bac70, st_ha_create_information * info=0x00000000076bc880)  Line 3328	C++
 	mysqld.exe!ha_create_table(THD * thd=0x0000000006a540f0, const char * path=0x00000000076bbcf0, const char * db=0x0000000001f68680, const char * table_name=0x0000000001f682f0, st_ha_create_information * create_info=0x00000000076bc880, bool update_create_info=false)  Line 3538 + 0x1f bytes	C++
 	mysqld.exe!rea_create_table(THD * thd=0x0000000006a540f0, const char * path=0x00000000076bbcf0, const char * db=0x0000000001f68680, const char * table_name=0x0000000001f682f0, st_ha_create_information * create_info=0x00000000076bc880, List<Create_field> & create_fields={...}, unsigned int keys=1, st_key * key_info=0x0000000001f69048, handler * file=0x0000000001f68da8)  Line 500 + 0x4a bytes	C++
 	mysqld.exe!mysql_create_table_no_lock(THD * thd=0x0000000006a540f0, const char * db=0x0000000001f68680, const char * table_name=0x0000000001f682f0, st_ha_create_information * create_info=0x00000000076bc880, Alter_info * alter_info=0x00000000076bc970, bool internal_tmp_table=false, unsigned int select_field_count=0)  Line 3705 + 0x65 bytes	C++
 	mysqld.exe!mysql_create_table(THD * thd=0x0000000006a540f0, const char * db=0x0000000001f68680, const char * table_name=0x0000000001f682f0, st_ha_create_information * create_info=0x00000000076bc880, Alter_info * alter_info=0x00000000076bc970, bool internal_tmp_table=false, unsigned int select_field_count=0)  Line 3860 + 0x49 bytes	C++
 	mysqld.exe!mysql_execute_command(THD * thd=0x0000000006a540f0)  Line 2735 + 0x47 bytes	C++
 	mysqld.exe!mysql_parse(THD * thd=0x0000000006a540f0, const char * inBuf=0x0000000001f67fe8, unsigned int length=58, const char * * found_semicolon=0x00000000076bf288)  Line 5943 + 0xd bytes	C++
 	mysqld.exe!dispatch_command(enum_server_command command=COM_QUERY, THD * thd=0x0000000006a540f0, char * packet=0x0000000006ab59c1, unsigned int packet_length=58)  Line 1051	C++
 	mysqld.exe!do_command(THD * thd=0x0000000006a540f0)  Line 731 + 0x23 bytes	C++
 	mysqld.exe!handle_one_connection(void * arg=0x0000000006a540f0)  Line 1146 + 0xa bytes	C++
 	mysqld.exe!pthread_start(void * p=0x00000000008dbef0)  Line 62	C
 	mysqld.exe!_callthreadstartex()  Line 348 + 0x17 bytes	C
 	mysqld.exe!_threadstartex(void * ptd=0x0000000006a78ed0)  Line 331	C
[14 Apr 2009 17:27] Vladislav Vaintroub
After applying the patch to the latest Falcon code, the crash introduced by the patch looks like:

 	
mysqld.exe!Error::error(const char * string=0x00000001409c1428, ...)  Line 73	C++
 	mysqld.exe!Error::assertionFailed(const char * text=0x00000001409f0848, const char * fileName=0x00000001409f0868, int line=109)  Line 79	C++
>	mysqld.exe!IndexNode::parseNode(Btn * indexNode=0x0000000003123414)  Line 109 + 0x30 bytes	C++
 	mysqld.exe!IndexNode::getNext(void * end=0x0000000003123434)  Line 133	C++
 	mysqld.exe!IndexPage::findNodeInLeaf(IndexKey * indexKey=0x00000000076b6750, IndexKey * foundKey=0x00000000076b3a80)  Line 228	C++
 	mysqld.exe!IndexRootPage::scanIndex(Dbb * dbb=0x0000000002942090, int indexId=1, int rootPage=10, IndexKey * lowKey=0x00000000076b6750, IndexKey * highKey=0x00000000076b6750, int searchFlags=0, unsigned int transId=0, Bitmap * bitmap=0x00000000076b6708)  Line 356 + 0x1a bytes	C++
 	mysqld.exe!Index::scanIndex(IndexKey * lowKey=0x00000000076b6750, IndexKey * highKey=0x00000000076b6750, int searchFlags=0, Transaction * transaction=0x0000000000000000, Bitmap * bitmap=0x00000000076b6708)  Line 578	C++
 	mysqld.exe!Table::checkUniqueIndex(Index * index=0x0000000002b55ed8, Transaction * transaction=0x0000000003522ac8, RecordVersion * record=0x0000000005a8f628, Sync * sync=0x00000000076b9278)  Line 2532	C++
 	mysqld.exe!Table::insertIndexes(Transaction * transaction=0x0000000003522ac8, RecordVersion * record=0x0000000005a8f628)  Line 1314 + 0x2f bytes	C++
 	mysqld.exe!Table::insert(Transaction * transaction=0x0000000003522ac8, int count=11, Nfs::Field * * fieldVector=0x0000000002b877c0, Value * * values=0x0000000002b8c528)  Line 405	C++
 	mysqld.exe!NInsert::evalStatement(Nfs::Statement * statement=0x0000000002b8e720)  Line 144	C++
 	mysqld.exe!Nfs::Statement::start(NNode * node=0x0000000002b870a0)  Line 492 + 0x15 bytes	C++
 	mysqld.exe!PreparedStatement::executeUpdate()  Line 87	C++
 	mysqld.exe!Nfs::Field::save()  Line 304	C++
 	mysqld.exe!Table::save()  Line 300	C++
 	mysqld.exe!Nfs::Statement::createTable(Syntax * syntax=0x0000000002b52a08)  Line 228	C++
 	mysqld.exe!Nfs::Statement::upgradeTable(Syntax * syntax=0x0000000002b52a08)  Line 1202	C++
 	mysqld.exe!Nfs::Statement::executeDDL()  Line 745	C++
 	mysqld.exe!Nfs::Statement::execute(const char * sqlString=0x00000000076ba760, bool isQuery=false)  Line 2730	C++
 	mysqld.exe!Nfs::Statement::execute(const char * sqlString=0x00000000076ba760)  Line 163	C++
 	mysqld.exe!StorageDatabase::createTable(StorageConnection * storageConnection=0x0000000002b90088, const char * tableName=0x0000000002b8b77c, const char * schemaName=0x0000000002b9005c, const char * sql=0x00000000076ba760, __int64 autoIncrementValue=0)  Line 205	C++
 	mysqld.exe!StorageTableShare::create(StorageConnection * storageConnection=0x0000000002b90088, const char * sql=0x00000000076ba760, __int64 autoIncrementValue=0)  Line 212 + 0x6c bytes	C++
 	mysqld.exe!StorageTable::create(const char * sql=0x00000000076ba760, __int64 autoIncrementValue=0)  Line 77	C++
 	mysqld.exe!StorageInterface::create(const char * mySqlName=0x00000000076bbcf0, TABLE * form=0x00000000076bac70, st_ha_create_information * info=0x00000000076bc880)  Line 908 + 0x39 bytes	C++
 	mysqld.exe!handler::ha_create(const char * name=0x00000000076bbcf0, TABLE * form=0x00000000076bac70, st_ha_create_information * info=0x00000000076bc880)  Line 3328	C++
 	mysqld.exe!ha_create_table(THD * thd=0x0000000006a540f0, const char * path=0x00000000076bbcf0, const char * db=0x0000000001f68680, const char * table_name=0x0000000001f682f0, st_ha_create_information * create_info=0x00000000076bc880, bool update_create_info=false)  Line 3538 + 0x1f bytes	C++
 	mysqld.exe!rea_create_table(THD * thd=0x0000000006a540f0, const char * path=0x00000000076bbcf0, const char * db=0x0000000001f68680, const char * table_name=0x0000000001f682f0, st_ha_create_information * create_info=0x00000000076bc880, List<Create_field> & create_fields={...}, unsigned int keys=1, st_key * key_info=0x0000000001f69048, handler * file=0x0000000001f68da8)  Line 500 + 0x4a bytes	C++
 	mysqld.exe!mysql_create_table_no_lock(THD * thd=0x0000000006a540f0, const char * db=0x0000000001f68680, const char * table_name=0x0000000001f682f0, st_ha_create_information * create_info=0x00000000076bc880, Alter_info * alter_info=0x00000000076bc970, bool internal_tmp_table=false, unsigned int select_field_count=0)  Line 3705 + 0x65 bytes	C++
 	mysqld.exe!mysql_create_table(THD * thd=0x0000000006a540f0, const char * db=0x0000000001f68680, const char * table_name=0x0000000001f682f0, st_ha_create_information * create_info=0x00000000076bc880, Alter_info * alter_info=0x00000000076bc970, bool internal_tmp_table=false, unsigned int select_field_count=0)  Line 3860 + 0x49 bytes	C++
 	mysqld.exe!mysql_execute_command(THD * thd=0x0000000006a540f0)  Line 2735 + 0x47 bytes	C++
 	mysqld.exe!mysql_parse(THD * thd=0x0000000006a540f0, const char * inBuf=0x0000000001f67fe8, unsigned int length=58, const char * * found_semicolon=0x00000000076bf288)  Line 5943 + 0xd bytes	C++
 	mysqld.exe!dispatch_command(enum_server_command command=COM_QUERY, THD * thd=0x0000000006a540f0, char * packet=0x0000000006ab59c1, unsigned int packet_length=58)  Line 1051	C++
 	mysqld.exe!do_command(THD * thd=0x0000000006a540f0)  Line 731 + 0x23 bytes	C++
 	mysqld.exe!handle_one_connection(void * arg=0x0000000006a540f0)  Line 1146 + 0xa bytes	C++
 	mysqld.exe!pthread_start(void * p=0x00000000008dbef0)  Line 62	C
 	mysqld.exe!_callthreadstartex()  Line 348 + 0x17 bytes	C
 	mysqld.exe!_threadstartex(void * ptd=0x0000000006a78ed0)  Line 331	C
[14 Apr 2009 19:14] 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/72053

3122 Vladislav Vaintroub	2009-04-14
      Bug#37056:  preliminary fix with a kludge, increasing retry-split  loop count, and so avoiding FATAL error .
      The attempt to properly fix the bug unfortunately failed at first attempt (need more time to analyze and implement it later)
[14 Apr 2009 20:35] Kevin Lewis
The temporary kludge of looping 1000 times instead of 10 is approved.  Bug is put back into 'In progress' while the the other fix is being debugged.
[15 Apr 2009 16:59] Bugs System
Pushed into 6.0.11-alpha (revid:hky@sun.com-20090415164923-9arx29ye5pzxd4zf) (version source revid:hky@sun.com-20090414213212-ibcjs12ic1v2h0e5) (merge vers: 6.0.11-alpha) (pib:6)
[29 Apr 2009 14:32] Kevin Lewis
Vlad has implemented a temporary solution to this assert by increasing the loop count to 1000 instead of 10.  This solution seems to effectively reduce the occurrence of this bug so that it is not currently seen.

What is left is probably not a Beta bug anymore.  So to keep this bug classified as BETA bug, I will open a new bug for a better fix.  Vlad has proposed a better patch here; http://lists.mysql.com/commits/72043.  But it causes new crashes.

See Bug#44542-Falcon needs a redesign of IndexRootPage::addIndexEntry
[15 May 2009 14:11] MC Brown
An entry has been added to the 6.0.11 changelog: 

When creating an index on a Falcon table with a very large dataset, mysqld would crash.