Bug #38130 Falcon assertion in IndexNode::expandKey offset + length <= MAX_PHYSICAL_KEY_LEN
Submitted: 15 Jul 2008 10:35 Modified: 15 May 2009 16:17
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
Category:MySQL Server: Falcon storage engine Severity:S1 (Critical)
Version:6.0-falcon OS:Any
Assigned to: Lars-Erik Bjørk CPU Architecture:Any
Triage: Triaged: D1 (Critical)

[15 Jul 2008 10:35] Philip Stoev
While running a workload containing INSERT/DELETE/UPDATE/SELECT and LIMIT, Falcon asserted as follows:

#0  0x00110416 in __kernel_vsyscall ()
#1  0x00581c78 in pthread_kill () from /lib/libpthread.so.0
#2  0x087abf37 in my_write_core (sig=6) at stacktrace.c:307
#3  0x082a9947 in handle_segfault (sig=6) at mysqld.cc:2638
#4  <signal handler called>
#5  0x00110416 in __kernel_vsyscall ()
#6  0x00584fe0 in raise () from /lib/libpthread.so.0
#7  0x0856bd20 in Error::debugBreak () at Error.cpp:94
#8  0x0856bd9d in Error::error (string=0x894ec98 "assertion (%s) failed at line %d in file %s\n") at Error.cpp:71
#9  0x0856be47 in Error::assertionFailed (text=0x8950794 "offset + length <= MAX_PHYSICAL_KEY_LENGTH", fileName=0x8950768 "IndexNode.h", line=148)
    at Error.cpp:78
#10 0x0857ff4f in IndexNode::expandKey (this=0xb7570b60, indexKey=0xb7570b78) at IndexNode.h:148
#11 0x085fb8af in WalkIndex::getNextNode (this=0xb756b688) at WalkIndex.cpp:101
#12 0x085fb92b in WalkIndex::getNext (this=0xb756b688, lockForUpdate=false) at WalkIndex.cpp:65
#13 0x0850b386 in StorageDatabase::nextIndexed (this=0xb71ca130, storageTable=0xb501fb80, indexWalker=0xb756b688, lockForUpdate=false)
    at StorageDatabase.cpp:481
#14 0x08511ce8 in StorageTable::nextIndexed (this=0xb501fb80, recordNumber=0, lockForUpdate=false) at StorageTable.cpp:180
#15 0x08504b16 in StorageInterface::index_next (this=0xa6703298, buf=0xa6703460 "") at ha_falcon.cpp:1601
#16 0x08503743 in StorageInterface::read_range_first (this=0xa6703298, start_key=0xa670332c, end_key=0x0, eq_range_arg=false, sorted=true)
    at ha_falcon.cpp:1569
#17 0x083cb10e in handler::multi_range_read_next (this=0xa6703298, range_info=0xa7faec90) at handler.cc:4262
#18 0x083aba03 in QUICK_RANGE_SELECT::get_next (this=0xa940d30) at opt_range.cc:8518
#19 0x083c53ab in rr_quick (info=0xa8cbd6c) at records.cc:298
#20 0x0831ca57 in join_init_read_record (tab=0xa8cbd28) at sql_select.cc:14481
#21 0x08320699 in sub_select (join=0xa8ca938, join_tab=0xa8cbd28, end_of_records=false) at sql_select.cc:13636
#22 0x0832d37f in do_select (join=0xa8ca938, fields=0xaacf498, table=0x0, procedure=0x0) at sql_select.cc:13387
#23 0x0833fa62 in JOIN::exec (this=0xa8ca938) at sql_select.cc:2811
#24 0x0833af1b in mysql_select (thd=0xaace000, rref_pointer_array=0xaacf508, tables=0xa9fd6a0, wild_num=0, fields=@0xaacf498, conds=0xa9fe528, og_num=1,
    order=0xa9fe6c0, group=0x0, having=0x0, proc_param=0x0, select_options=2149337600, result=0xa9fe758, unit=0xaacf16c, select_lex=0xaacf404)
    at sql_select.cc:3001
#25 0x0833fd72 in handle_select (thd=0xaace000, lex=0xaacf110, result=0xa9fe758, setup_tables_done_option=0) at sql_select.cc:302
#26 0x082b8778 in execute_sqlcom_select (thd=0xaace000, all_tables=0xa9fd6a0) at sql_parse.cc:4847
#27 0x082b9f90 in mysql_execute_command (thd=0xaace000) at sql_parse.cc:2015
#28 0x082c2fc6 in mysql_parse (thd=0xaace000,
    inBuf=0xa9fd238 "SELECT X . int_key FROM D AS X LEFT JOIN A AS Y ON ( X . int_key = Y . int_key ) WHERE X . int_key > 180 ORDER BY X . int_key LIMIT 1",
    length=133, found_semicolon=0xa7fb0270) at sql_parse.cc:5811
#29 0x082c3a3a in dispatch_command (command=COM_QUERY, thd=0xaace000, packet=0xaa98081 "", packet_length=133) at sql_parse.cc:1051
#30 0x082c4d04 in do_command (thd=0xaace000) at sql_parse.cc:724
#31 0x082b29d3 in handle_one_connection (arg=0xaace000) at sql_connect.cc:1153
#32 0x0057d32f in start_thread () from /lib/libpthread.so.0
#33 0x0049a27e in clone () from /lib/libc.so.6

The assertion is here:

146     inline void IndexNode::expandKey(IndexKey *indexKey)
147     {
148             ASSERT (offset + length <= MAX_PHYSICAL_KEY_LENGTH); <<<< HERE
150             if (length)
151                     memcpy (indexKey->key + offset, key, length);

(gdb) print offset
$3 = 0
(gdb) print length
$4 = 15874
$5 = 10809

How to repeat:
If this happens again, a test case will be provided.
[15 Jul 2008 14:05] Philip Stoev
Grammar file for bug 38130

Attachment: bug38130.yy (application/octet-stream, text), 1016 bytes.

[15 Jul 2008 14:08] Philip Stoev
I just uploaded a gramma file for this bug. To reproduce, please clone the mysql-test-extra-6.0 tree and execute

$ cd mysql-test-extra-6.0/mysql-test/gentest
$ perl runall.pl \
 --basedir=/path/to/mysql-6.0-falcon \
 --grammar=/location/of/bug38130.yy \
 --engine=falcon \
 --mysqld=--falcon_lock_wait_timeout=1 \

On a dual-core virtualized 1.4ghz it takes 12 min at 10 threads to crash, 141460 queries, 2602 rollbacks, 2558 commits.
[3 Jan 2009 11:37] Philip Stoev
Still present in 6.0-falcon-team. To reproduce within 5 min, execute:

$ perl runall.pl \
  --mysqld=--falcon-page-size=4K \
  --vardir=/tmp/vardir \
  --rows=10000 \
  --threads=4 \
  --mask=58 \
  --queries=1000000 \
  --duration=300 \
  --basedir=/build/bzr/6.0-falcon-team \
  --engine=Falcon \
  --grammar=conf/combinations.yy \
  --gendata=conf/combinations.zz \
  --reporter=Backtrace \
  --mysqld=--loose-falcon-lock-wait-timeout=1 \
[27 Feb 2009 9:39] Lars-Erik Bjørk
This bug is closely related to bug#42341

The difference seems to be that the garbage, read behind the END_BUCKET node, is not caught in the first consistency check, but in a later check.

This crash also disappears when applying the change suggested in the report for bug#42341
[2 Mar 2009 8:17] 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:


3043 lars-erik.bjork@sun.com	2009-03-02
      This is a patch for 
      bug#42341 Falcon assertion (key - (UCHAR*) 
      indexNode < 14) in IndexNode::parseNode
      bug#38130 Falcon assertion in IndexNode::expandKey 
      offset + length <= MAX_PHYSICAL_KEY_LENGTH
      These crashes happen because we are trying to use the 
      data behind the last node in the bucket, when we 
      are walking the index. The reason for this is that 
      the node with the special record number -1 (which 
      indicates END_BUCKET) is the only node in the page.
      WalkIndex::getNextNode has the following piece of code:
      int32 WalkIndex::getNextNode(void)
          for (;; first = true)
                  if (first)
                      first = false;
                      recordNumber = node.getNumber();
                      if (recordNumber >= 0)
                          return recordNumber;
                      else if (recordNumber == END_LEVEL)
                          return -1;
      We fail to check if recordNumber == END_BUCKET.
      In the case of bug#42341, we try to parse some
      garbage data in IndexNode::parseNode and assert on
      a consistency check.
      In the case of bug#38130, we slip through this
      consistency check, but assert on a second check
      in IndexNode::expandKey 
      Changing the if from
      else if (recordNumber == END_LEVEL)
      else if (recordNumber == END_LEVEL || recordNumber == END_BUCKET)
      prevents both crashes.
      modified file 'storage/falcon/WalkIndex.cpp'
      Changed the if to prevent reading behind the
      END_BUCKET node.
[2 Mar 2009 14:39] Kevin Lewis
Patch approved
[2 Apr 2009 17:38] Bugs System
Pushed into 6.0.11-alpha (revid:hky@sun.com-20090402144811-yc5kp8g0rjnhz7vy) (version source revid:christopher.powers@sun.com-20090304040340-b4zoglfws0iswqm1) (merge vers: 6.0.11-alpha) (pib:6)
[15 May 2009 16:17] MC Brown
Internal/test fix. No changelog entry required.