Bug #42006 Running falcon_bug_22207-big on 32-bit Linux leads to crash
Submitted: 9 Jan 2009 21:22 Modified: 15 May 2009 13:28
Reporter: Hakan Küçükyılmaz Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S3 (Non-critical)
Version:mysql-6.0-falcon-team OS:Linux (32-bit)
Assigned to: Kevin Lewis CPU Architecture:Any
Tags: F_SCAVENGER

[9 Jan 2009 21:22] Hakan Küçükyılmaz
Description:
Running falcon_bug_22207-big on 32-bit Linux leads to crash

How to repeat:
Use latest mysql-6.0-falcon-team tree
BUILD/compile-pentium-max-no-ndb

 ./mysql-test-run.pl --big-test --suite-timeout=6360 --testcase-timeout=3600 --suite=falcon falcon_bug_22207-big falcon_bug_22207-big falcon_bug_22207-big

falcon.falcon_bug_22207-big    [ fail ]

mysqltest: At line 68: query 'UPDATE t1 SET c2 = c2 + 1, c1 = concat(rpad(conv(c2,10,10),10,'_'), repeat(c3, 40))' failed: 2013: Lost connection to MySQL server during query

090110  0:21:15 - mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 60005 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x9bfdcf8
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0xaf156fa8 thread_stack 0x30c00
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(my_print_stacktrace+0x2d) [0x872ac6d]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(handle_segfault+0x3ff) [0x828ffcf]
[0xb7fd1400]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(MemFreeBlock::remove()+0x174) [0x8592254]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(MemFreeBlock::findNextLargest(int)+0xae) [0x859233e]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(MemMgr::alloc(unsigned int)+0xb5) [0x851ca85]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(MemMgrPoolAllocate(MemMgr*, unsigned int)+0x5a) [0x851d
7da]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(Table::allocRecordVersion(Format*, Transaction*, Record
*)+0x5d) [0x84b731d]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(Table::update(Transaction*, Record*, Stream*)+0x2ec) [0
x84c0d4c]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(StorageDatabase::updateRow(StorageConnection*, Table*,
Record*, Stream*)+0x31) [0x84a9651]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(StorageTable::updateRow(int)+0x64) [0x84af574]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(StorageInterface::update_row(unsigned char const*, unsi
gned char*)+0x7e) [0x84a4bbe]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(handler::ha_update_row(unsigned char const*, unsigned c
har*)+0x6d) [0x839d08d]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>
&, Item*, unsigned int, st_order*, unsigned long long, enum_duplicates, bool)+0x13c8) [0x8335fa8]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(mysql_execute_command(THD*)+0x4bb9) [0x82a5389]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(mysql_parse(THD*, char const*, unsigned int, char const
**)+0x371) [0x82a7c51]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(dispatch_command(enum_server_command, THD*, char*, unsi
gned int)+0xa8d) [0x82a8bad]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(do_command(THD*)+0xc3) [0x82a9dc3]
/home/hakan/work/mysql/mysql-6.0-falcon-team/sql/mysqld(handle_one_connection+0x1aa) [0x829a70a]
/lib/tls/i686/cmov/libpthread.so.0 [0xb7f8c50f]
/lib/tls/i686/cmov/libc.so.6(clone+0x5e) [0xb7d947ee]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x9c51b50 = UPDATE t1 SET c2 = c2 + 1, c1 = concat(rpad(conv(c2,10,10),10,'_'), repeat(c3, 40))
thd->thread_id=1
thd->killed=NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file
[10 Jan 2009 19:38] Hakan Küçükyılmaz
Backtrace from 32-bit Mac OS X/PPC run

Program received signal EXC_BAD_ACCESS, Could not access memory.
Reason: KERN_INVALID_ADDRESS at address: 0x8209a81a
[Switching to process 22029 thread 0x4003]
MemFreeBlock::remove (this=0x8209a80a) at MemFreeBlock.cpp:384
384                     int parentDelta = (nodeParent->smaller == node) ? 1 : -1;
(gdb) 
(gdb) p parentDelta
No symbol "parentDelta" in current context.
(gdb) p nodeParent
$1 = (MemFreeBlock *) 0xa815059
(gdb) p nodeParent->smaller
$2 = (MemFreeBlock *) 0x812b980a
(gdb) p node
$3 = (MemFreeBlock *) 0x908ea8
(gdb) l
379                             node->balance += delta;
380
381                             return;
382                             }
383
384                     int parentDelta = (nodeParent->smaller == node) ? 1 : -1;
385                     node->balance += delta;
386
387                     if (node->balance == delta)
388                             break;
(gdb) p node->balance
$4 = -3233832
(gdb) p node
$5 = (MemFreeBlock *) 0x908ea8
(gdb) p *node
$6 = {
  <MemBigObject> = {
    <MemBigHeader> = {
      next = 0x0, 
      prior = 0x0
    }, 
    members of MemBigObject: 
    memHeader = {
      pool = 0x0, 
      length = 0
    }
  }, 
  members of MemFreeBlock: 
  smaller = 0x0, 
  larger = 0xa8209a8, 
  parent = 0x0, 
  nextTwin = 0x908ea8, 
  priorTwin = 0x908ea8, 
  balance = -3233832
}
(gdb) 
(gdb) p *nodeParent->smaller
Cannot access memory at address 0x812b980a
[13 Jan 2009 17:32] MySQL Verification Team
Verified on 64-bit too:

=======================================================

TEST                           RESULT         TIME (ms)
-------------------------------------------------------

falcon.falcon_bug_22207-big    [ fail ]

mysqltest: At line 68: query 'UPDATE t1 SET c2 = c2 + 1, c1 = concat(rpad(conv(c2,10,10),10,'_'), repeat(c3, 40))' failed: 2013: Lost connection to MySQL server during query

The result from queries just before the failure was:
< snip >
600000____EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEE
600000____FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
600000____GGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGG
600000____HHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHH
600000____IIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIII
600000____JJJJJJJJJJJJJJJJJJJJJJJJJJJJJJJJJJJJJJJJ
600000____KKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKK
SELECT c1 from t1;
[13 Jan 2009 19:35] Kevin Lewis
Assigning this to myself by way of proxy for Jim Starkey, who agreed to look into it.
[15 Jan 2009 16:43] Hakan Küçükyılmaz
Latest changes in mysql-6.0-falcon-team tree fixed this issue:

Linux 32-bit:
TEST                           RESULT         TIME (ms)
-------------------------------------------------------

falcon.falcon_bug_22207-big    [ pass ]         636862
falcon.falcon_bug_22207-big    [ pass ]         636507
falcon.falcon_bug_22207-big    [ pass ]         631690
falcon.falcon_bug_22207-big    [ pass ]         633473
falcon.falcon_bug_22207-big    [ pass ]         636163
falcon.falcon_bug_22207-big    [ pass ]         637584
falcon.falcon_bug_22207-big    [ pass ]         633753
falcon.falcon_bug_22207-big    [ pass ]         631290

Mac 32-bit:

falcon.falcon_bug_22207-big    [ pass ]        2853551
falcon.falcon_bug_22207-big    [ pass ]        2879854
falcon.falcon_bug_22207-big    [ pass ]        2870679
falcon.falcon_bug_22207-big    [ pass ]        2841266
[15 Jan 2009 16:54] Kevin Lewis
I can probably take credit for fixing this with the following patch.  But that also means I can take credit for causing this problem as well :)
See also Bug#42080 & Bug#41831.

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/63294

2959 Kevin Lewis	2009-01-14
      Bug#42080, Bug#41831  In both of these bugs, the scavenger was pruning
      records that it should not have.  The record version chosen to start 
      pruning is returned from RecordScavenge::inventoryRecord().  This 
      function is improved so that only the oldest visible record is returned.
      In addition, Recordversion::committedbefore() is added to simplify 
      the code and read RecordVersion::transaction only once since it can be 
      set to null at any time.
[15 May 2009 13:28] MC Brown
Internal/test fix only. No changelog entry required.