Bug #43146 Falcon crash in EncodedDataStream::skip

Submitted: 24 Feb 2009 13:25 Modified: 15 May 2009 13:25
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S1 (Critical)
Version:6.0-falcon-team, 6.0 bzr OS:Any
Assigned to: Kevin Lewis CPU Architecture:Any
Tags: F_RECORD TREE

[24 Feb 2009 13:25] Philip Stoev
Description:
When executing a RQG workload, Falcon crashed as follows:

#4  0x00000000009e27b2 in EncodedDataStream::skip (
    ptr=0x2aaac07872e6 <Address 0x2aaac07872e6 out of bounds>)
    at EncodedDataStream.h:350
#5  0x0000000000a1a626 in Record::getEncodedValue (this=0x13552130,
    fieldId=25, value=0x441afd00) at Record.cpp:662
#6  0x0000000000a1b66c in Record::getRawValue (this=0x13552130, fieldId=25,
    value=0x441afd00) at Record.cpp:370
#7  0x0000000000a1b9df in Record::getValue (this=0x13552130, fieldId=25,
    value=0x441afd00) at Record.cpp:322
#8  0x00000000009f014c in Index::makeKey (this=0x2aaaaae46aa8,
    record=0x13552130, key=0x441b0260) at Index.cpp:636
#9  0x00000000009f02f0 in Index::duplicateKey (this=0x2aaaaae46aa8,
    key=0x441b2d20, record=0x13552130) at Index.cpp:698
#10 0x00000000009f04a4 in Index::garbageCollect (this=0x2aaaaae46aa8,
    leaving=0x13114380, staying=0x13552130, transaction=0x0, quiet=false)
    at Index.cpp:656
#11 0x000000000099c3cd in Table::garbageCollect (this=0x2aaaaadb4308,
    leaving=0x13114380, staying=0x13552130, transaction=0x0, quiet=false)
    at Table.cpp:2146
#12 0x0000000000a1c891 in RecordLeaf::pruneRecords (this=0x2aaaaae4eca0,
    table=0x2aaaaadb4308, base=1, recordScavenge=0x441b5b40)
    at RecordLeaf.cpp:163
#13 0x0000000000a8e737 in RecordGroup::pruneRecords (this=0x2aaaaae4e950,
    table=0x2aaaaadb4308, base=0, recordScavenge=0x441b5b40)
    at RecordGroup.cpp:122
#14 0x0000000000993017 in Table::pruneRecords (this=0x2aaaaadb4308,
    recordScavenge=0x441b5b40) at Table.cpp:1910
#15 0x00000000009ca3fb in Database::pruneRecords (this=0x2aaaaabecbc8,
    recordScavenge=0x441b5b40) at Database.cpp:1873
#16 0x00000000009ca535 in Database::scavengeRecords (this=0x2aaaaabecbc8,
    forced=false) at Database.cpp:1821
#17 0x00000000009ca8da in Database::scavenge (this=0x2aaaaabecbc8,
    forced=false) at Database.cpp:1777
#18 0x00000000009ca9fc in Database::scavengerThreadMain (this=0x2aaaaabecbc8)
    at Database.cpp:1950
#19 0x00000000009caa8b in Database::scavengerThreadMain (
    database=0x2aaaaabecbc8) at Database.cpp:1939
#20 0x00000000009a40f9 in Thread::thread (this=0x2aaaaadf7e78)
    at Thread.cpp:166
#21 0x00000000009a4321 in Thread::thread (parameter=0x2aaaaadf7e78)
    at Thread.cpp:145

(gdb) list
345             static int              init(void);
346             static const UCHAR* decode (const UCHAR *ptr, Value *value, bool copyFlag);
347
348             inline static const unsigned char* skip (const unsigned char *ptr)
349                     {
350                     int length = lengths[*ptr++]; <<<<<<< HERE
351
352                     if (length < 0)
353                             {
354                             int count = 0;

(gdb) print ptr
$1 = (const unsigned char *) 0x2aaac07872e6 <Address 0x2aaac07872e6 out of bounds>

in Record::getEncodedValue:

(gdb) list
657                                     {
658                                     const UCHAR *p = (UCHAR*) data.record + vector[highWater];
659
660                                     while (highWater < index)
661                                             {
662                                             const UCHAR *q = EncodedDataStream::skip(p); <<<<<<<< HERE
663                                             vector[++highWater] = (USHORT) (q - (UCHAR*) data.record);
664                                             p = q;
665                                             }
666                                     }

(gdb) print data
$12 = {record = 0x2aaac0297290 "L"}
(gdb) print data.record
$13 = 0x2aaac0297290 "L"
(gdb) print p
$14 = (const UCHAR *) 0x2aaac07872e6 <Address 0x2aaac07872e6 out of bounds>
(gdb) print q
$15 = (const UCHAR *) 0x2aaac07872e6 <Address 0x2aaac07872e6 out of bounds>

How to repeat:
  perl runall.pl  --mem --rows=1000 --threads=4 --mysqld=--falcon-checkpoint-schedule='1 1 1 1 1'    --basedir=/export/home/pb2/test/sb_1-342525-1235379243.16/mysql-6.0.10-alpha-linux-x86_64-test   --mask=3334   --queries=10000000   --duration=900   --engine=Falcon   --grammar=conf/combinations.yy   --gendata=conf/combinations.zz   --reporters=Deadlock,ErrorLog,Backtrace,Recovery   --mysqld=--loose-falcon-lock-wait-timeout=1   --mysqld=--loose-innodb-lock-wait-timeout=1   --mysqld=--log-output=none   --mysqld=--skip-safemalloc  

or 

   perl runall.pl   --rows=10000 --threads=16 --mysqld=--falcon-record-chill-threshold=1    --basedir=/export/home/pb2/test/sb_1-342525-1235379243.16/mysql-6.0.10-alpha-linux-x86_64-test   --mask=1764   --queries=10000000   --duration=900   --engine=Falcon   --grammar=conf/combinations.yy   --gendata=conf/combinations.zz   --reporters=Deadlock,ErrorLog,Backtrace,Recovery   --mysqld=--loose-falcon-lock-wait-timeout=1   --mysqld=--loose-innodb-lock-wait-timeout=1   --mysqld=--log-output=none   --mysqld=--skip-safemalloc
[24 Feb 2009 15:01] Sveta Smirnova
Thank you for the report.

Crash verified using current 6.0 tree:

#0  0x002ce402 in __kernel_vsyscall ()
#0  0x002ce402 in __kernel_vsyscall ()
#1  0x0046264f in pthread_kill () from /lib/libpthread.so.0
#2  0x0881c8e7 in my_write_core (sig=11) at stacktrace.c:309
#3  0x082bc7a8 in handle_segfault (sig=11) at mysqld.cc:2689
#4  <signal handler called>
#5  0x0035841d in memmove () from /lib/libc.so.6
#6  0x082b9880 in well_formed_copy_nchars (to_cs=0x8ba37e0, to=0xb49b023 "20011210000338", ' ' <repeats 50 times>, "##\f\037A\022", to_length=64, from_cs=0x8ba37e0, from=0x0, from_length=64, nchars=64, 
    well_formed_error_pos=0x976ee908, cannot_convert_error_pos=0x976ee904, from_end_pos=0x976ee900) at sql_string.cc:1018
#7  0x08290df6 in Field_string::store (this=0xb49c360, from=0x0, length=4294967295, cs=0x8ba37e0) at field.cc:6304
#8  0x0855dc28 in StorageInterface::decodeRecord (this=0xb49a860, buf=0xb49ac48 "\001") at ha_falcon.cpp:3231
#9  0x0855e304 in StorageInterface::rnd_next (this=0xb49a860, buf=0xb49ac48 "\001") at ha_falcon.cpp:652
#10 0x084146b9 in ha_partition::rnd_next (this=0xb49a478, buf=0xb49ac48 "\001") at ha_partition.cc:3541
#11 0x083fffc7 in find_all_keys (param=0x976eed54, select=0x0, sort_keys=0xb7401ca0, buffpek_pointers=0x976eeb7c, tempfile=0x976eec68, indexfile=0x0) at filesort.cc:587
#12 0x08401d2a in filesort (thd=0xb450d68, table=0xb476d20, sortorder=0xb4631d8, s_length=1, select=0x0, max_rows=6, sort_positions=true, examined_rows=0x976ef038) at filesort.cc:245
#13 0x083889b3 in mysql_update (thd=0xb450d68, table_list=0xb462a20, fields=@0xb45201c, values=@0xb45224c, conds=0x0, order_num=1, order=0xb4630e8, limit=6, handle_duplicates=DUP_ERROR, ignore=false)
    at sql_update.cc:426
#14 0x082d3d88 in mysql_execute_command (thd=0xb450d68) at sql_parse.cc:3014
#15 0x082da2bd in mysql_parse (thd=0xb450d68, inBuf=0xb4627b0 "UPDATE `table1000_falcon_key_pk_parts_2_int_autoinc` SET `char_64_utf8_not_null` = 'so'  ORDER BY `enum_utf8_not_null` LIMIT 6", 
    length=126, found_semicolon=0x976eff20) at sql_parse.cc:5752
#16 0x082dacff in dispatch_command (command=COM_QUERY, thd=0xb450d68, 
    packet=0xb456731 "UPDATE `table1000_falcon_key_pk_parts_2_int_autoinc` SET `char_64_utf8_not_null` = 'so'  ORDER BY `enum_utf8_not_null` LIMIT 6", packet_length=126) at sql_parse.cc:1009
#17 0x082dc063 in do_command (thd=0xb450d68) at sql_parse.cc:691
#18 0x082c9f0b in handle_one_connection (arg=0xb450d68) at sql_connect.cc:1146
#19 0x0045fbd4 in start_thread () from /lib/libpthread.so.0
#20 0x003b74fe in clone () from /lib/libc.so.6
Using host libthread_db library "/lib/libthread_db.so.1".
Core was generated by `/users/ssmirnova/build/mysql-6.0/libexec/mysqld --no-defaults --basedir=/users/'.
Program terminated with signal 11, Segmentation fault.

warning: svr4_current_sos: Can't read pathname for load map: Input/output error
[24 Feb 2009 15:31] Sveta Smirnova
Philip, second run gave backtrace similar to one you described:

Thread 23 (process 14801):
#0  0x08846527 in my_tosort_unicode (uni_plane=0x8b83820, wc=0xa4648dec) at ctype-utf8.c:1970
#1  0x08846422 in my_strnxfrm_unicode (cs=0x8b84120, dst=0xa464e804 "", dstlen=10809, nweights=1100, src=0xa4648e84 "et50522160546wjfhiuekonxslufrypalaepbppfyxrbwhvdcdlnuybkedmhhqb", srclen=3, flags=0)
    at ctype-utf8.c:2002
#2  0x08556d9c in falcon_strnxfrm (cs=0x8b84120, dst=0xa464e804 "", dstlen=10809, nweights=1100, src=0xa4648e83 "get50522160546wjfhiuekonxslufrypalaepbppfyxrbwhvdcdlnuybkedmhhqb", srclen=3)
    at ha_falcon.cpp:299
#3  0x085e3ab7 in MySQLCollation::makeKey (this=0xb70958a0, value=0xa464e43c, key=0xa464e7f4, partialKey=0, maxKeyLength=1100) at MySQLCollation.cpp:72
#4  0x085d1d41 in Index::makeKey (this=0xb70ad198, field=0xb70a4ca0, value=0xa464e43c, segment=0, indexKey=0xa464e7f4) at Index.cpp:312
#5  0x085d1ebc in Index::makeKey (this=0xb70ad198, count=1, values=0xa464e73c, indexKey=0xa464e7f4) at Index.cpp:363
#6  0x085d2564 in Index::makeKey (this=0xb70ad198, record=0x9eb91a48, key=0xa464e7f4) at Index.cpp:639
#7  0x085d26a0 in Index::duplicateKey (this=0xb70ad198, key=0xa4651288, record=0x9eb91a48) at Index.cpp:698
#8  0x085d281a in Index::garbageCollect (this=0xb70ad198, leaving=0x96891458, staying=0x969a3e48, transaction=0x0, quiet=false) at Index.cpp:656
#9  0x08584233 in Table::garbageCollect (this=0xb73d7020, leaving=0x96891458, staying=0x969a3e48, transaction=0x0, quiet=false) at Table.cpp:2145
#10 0x085fc8f5 in RecordLeaf::pruneRecords (this=0xb70afc08, table=0xb73d7020, base=0, recordScavenge=0xa4653f40) at RecordLeaf.cpp:163
#11 0x086681d7 in RecordGroup::pruneRecords (this=0xb70b19f0, table=0xb73d7020, base=0, recordScavenge=0xa4653f40) at RecordGroup.cpp:122
#12 0x0857cf2b in Table::pruneRecords (this=0xb73d7020, recordScavenge=0xa4653f40) at Table.cpp:1909
#13 0x085ae1a6 in Database::pruneRecords (this=0xb727c640, recordScavenge=0xa4653f40) at Database.cpp:1868
#14 0x085b0dac in Database::scavengeRecords (this=0xb727c640, forced=false) at Database.cpp:1816
#15 0x085b1161 in Database::scavenge (this=0xb727c640, forced=false) at Database.cpp:1776
#16 0x085b1270 in Database::scavengerThreadMain (this=0xb727c640) at Database.cpp:1945
#17 0x085b131b in Database::scavengerThreadMain (database=0xb727c640) at Database.cpp:1934
#18 0x0858b959 in Thread::thread (this=0xb70831d8) at Thread.cpp:166
#19 0x0858be19 in Thread::thread (parameter=0xb70831d8) at Thread.cpp:145
#20 0x0045fbd4 in start_thread () from /lib/libpthread.so.0
#21 0x003b74fe in clone () from /lib/libc.so.6
Current language:  auto; currently c

So probably no new test case needed.
[30 Mar 2009 22:04] Kevin Lewis
Philip reported that this problem cannot be repeated after the changes the following changes were added;
1) Olav created a TransactionState object that outlives the Transaction
2) A CycleManager was added to protect doomed records until after all temporary stack pointers to them have gone away.
[15 May 2009 13:25] MC Brown
Internal/test fix. No changelog entry required.
[15 May 2009 13:40] MC Brown
A note have been added to the 6.0.11 changelog: 

The Falcon CycleManager has been updated, which addresses a number of issues when examining records in various transaction states and their visisbility/isolation in relation to other threads.

Portions of this website are copyright © 2001, 2002 The PHP Group

Page generated in 0.060 sec. using MySQL 8.4.7-u6-cloud

Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the respective copyright holders.
It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.