Bug #43858 falcon_limit crashes in Transaction::visible()
Submitted: 25 Mar 2009 13:34 Modified: 15 May 2009 16:09
Reporter: Olav Sandstå Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S2 (Serious)
Version:6.0.11-alpha OS:Any
Assigned to: Olav Sandstå CPU Architecture:Any
Tags: F_TRANSACTION, pb2
Triage: Triaged: D1 (Critical)

[25 Mar 2009 13:34] Olav Sandstå
Description:
When running the RQG test falcon_limit is sometimes crashes with a segmentation fault and the following call stack:

#3  <signal handler called>
#4  0x00661a20 in Transaction::visible (this=0x1f86a00, transState=0xeeeeeeee, 
    forWhat=0) at Transaction.cpp:751
#5  0x00661b6c in Transaction::visible (this=0x1f86a00, transaction=0x1f78fe8, 
    transId=8370, forWhat=0) at Transaction.cpp:724
#6  0x00700e2c in RecordVersion::fetchVersionRecursive (this=0x9a0c790, 
    trans=0x1f86a00) at RecordVersion.cpp:166
#7  0x00700ca0 in RecordVersion::fetchVersion (this=0x9a0c790, trans=0x1f86a00)
    at RecordVersion.cpp:145
#8  0x006cfe80 in IndexWalker::getValidatedRecord (this=0x2595658, 
    recordId=2027, lockForUpdate=false) at IndexWalker.cpp:160
#9  0x00779c90 in WalkIndex::getNext (this=0x2595658, lockForUpdate=false)
    at WalkIndex.cpp:76
#10 0x0062eecc in StorageDatabase::nextIndexed (this=0x1dfded0, 
    storageTable=0x251f370, indexWalker=0x2595658, lockForUpdate=false)
    at StorageDatabase.cpp:490
#11 0x00638de4 in StorageTable::nextIndexed (this=0x251f370, recordNumber=328, 
    lockForUpdate=false) at StorageTable.cpp:169
#12 0x0061c81c in StorageInterface::index_next (this=0xafc6378, 
    buf=0xafc6560 "") at ha_falcon.cpp:1853
#13 0x00372ec0 in join_read_next (info=0xb07efbc) at sql_select.cc:17092
#14 0x0036e610 in sub_select (join=0xb3721b0, join_tab=0xb07ef78, 
    end_of_records=false) at sql_select.cc:16266
#15 0x0036d118 in do_select (join=0xb3721b0, fields=0xb289550, table=0x0, 
    procedure=0x0) at sql_select.cc:15807
#16 0x00390138 in JOIN::exec (this=0xb3721b0) at sql_select.cc:2881
#17 0x003906f4 in mysql_select (thd=0xb2881a8, rref_pointer_array=0xb2895c0, 
    tables=0xb02c440, wild_num=0, fields=@0xb289550, conds=0xb02d0d8, 
    og_num=1, order=0xb02d2a8, group=0x0, having=0x0, proc_param=0x0, 
    select_options=2149337600, result=0xb02d340, unit=0xb289218, 
    select_lex=0xb2894b8) at sql_select.cc:3062
#18 0x00390b08 in handle_select (thd=0xb2881a8, lex=0xb2891b8, 
    result=0xb02d340, setup_tables_done_option=0) at sql_select.cc:314
#19 0x002bdb1c in execute_sqlcom_select (thd=0xb2881a8, all_tables=0xb02c440)
    at sql_parse.cc:4768
#20 0x002c5878 in mysql_execute_command (thd=0xb2881a8) at sql_parse.cc:2069
#21 0x002cfd64 in mysql_parse (thd=0xb2881a8, 
    inBuf=0xb02c1c0 "SELECT X . `datetime_key` FROM E AS X LEFT JOIN A AS Y USING ( `int_key` ) WHERE X . `datetime_key` = 5 ORDER BY X . `date_key` LIMIT 9", 
    length=135, found_semicolon=0xfd671dc8) at sql_parse.cc:5783
#22 0x002d0888 in dispatch_command (command=COM_QUERY, thd=0xb2881a8, 
    packet=0xb27e1a9 "", packet_length=135) at sql_parse.cc:1009
#23 0x002d2018 in do_command (thd=0xb2881a8) at sql_parse.cc:691
#24 0x002b9c48 in handle_one_connection (arg=0xb2881a8) at sql_connect.cc:1146
#25 0xfef3fff8 in _lwp_start () from /lib/libc.so.1
#26 0xfef3fff8 in _lwp_start () from /lib/libc.so.1
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

warning: Lowest section in /lib/libpthread.so.1 is .dynamic at 00000074

warning: Lowest section in /lib/libthread.so.1 is .dynamic at 00000074

warning: Lowest section in /lib/libdl.so.1 is .dynamic at 00000094
Core was generated by `/export/home/pb2/test/sb_1-419160-1237881798.01/mysql-6.0.11-alpha-solaris10-sp'.
Program terminated with signal 10, Bus error.
#0  0xfef411e4 in _lwp_kill () from /lib/libc.so.1

Thread 34 (process 2451892    ):
#0  0xfef41504 in _write () from /lib/libc.so.1
#1  0xfef32bb0 in write () from /lib/libc.so.1
#2  0x009e16f0 in vio_write (vio=0xafc3f20, buf=0xb25a1a8 "\001", size=583)
    at viosocket.c:111
#3  0x00294f24 in net_real_write (net=0xb1fe25c, packet=0xb25a1a8 "\001", 
    len=583) at net_serv.cc:638
#4  0x002958f4 in net_flush (net=0xb1fe25c) at net_serv.cc:344
#5  0x0029793c in net_send_eof (thd=0xb1fe1c0, server_status=33, 
    statement_warn_count=171) at protocol.cc:268
#6  0x002985f0 in Protocol::send_eof (this=0xb1fe4cc, server_status=33, 
    statement_warn_count=171) at protocol.cc:519
#7  0x00298390 in Protocol::end_statement (this=0xb1fe4cc) at protocol.cc:465
#8  0x002d1a7c in dispatch_command (command=COM_QUERY, thd=0xb1fe1c0, 
    packet=0xb25a1a9 "", packet_length=80) at sql_parse.cc:1405
#9  0x002d2018 in do_command (thd=0xb1fe1c0) at sql_parse.cc:691
#10 0x002b9c48 in handle_one_connection (arg=0xb1fe1c0) at sql_connect.cc:1146
#11 0xfef3fff8 in _lwp_start () from /lib/libc.so.1
#12 0xfef3fff8 in _lwp_start () from /lib/libc.so.1
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 33 (process 2386356    ):
#0  0xfef41504 in _write () from /lib/libc.so.1
#1  0xfef32bb0 in write () from /lib/libc.so.1
#2  0x009e16f0 in vio_write (vio=0xafc2f00, buf=0xb21c1a0 "-", size=49)
    at viosocket.c:111
#3  0x00294f24 in net_real_write (net=0xadc625c, packet=0xb21c1a0 "-", len=49)
    at net_serv.cc:638
#4  0x002958f4 in net_flush (net=0xadc625c) at net_serv.cc:344
#5  0x00295cac in net_write_command (net=0xadc625c, command=255 '�', 
    header=0xcb13e8 "", head_len=0, 
    packet=0xfd6f15e8 "V\004#42000Column 'varchar_key' specified twice", 
    len=44) at net_serv.cc:482
#6  0x00297ba0 in net_send_error_packet (thd=0xadc61c0, sql_errno=1110, 
    err=0xfd6f15e8 "V\004#42000Column 'varchar_key' specified twice", 
    sqlstate=0xadc7da8 "42000") at protocol.cc:362
#7  0x00298668 in Protocol::send_error (this=0xadc64cc, sql_errno=1110, 
    err_msg=0xadc7ba2 "Column 'varchar_key' specified twice", 
    sql_state=0xadc7da8 "42000") at protocol.cc:535
#8  0x0029832c in Protocol::end_statement (this=0xadc64cc) at protocol.cc:461
#9  0x002d1a7c in dispatch_command (command=COM_QUERY, thd=0xadc61c0, 
    packet=0xb21c1a1 "", packet_length=84) at sql_parse.cc:1405
#10 0x002d2018 in do_command (thd=0xadc61c0) at sql_parse.cc:691
#11 0x002b9c48 in handle_one_connection (arg=0xadc61c0) at sql_connect.cc:1146
#12 0xfef3fff8 in _lwp_start () from /lib/libc.so.1
#13 0xfef3fff8 in _lwp_start () from /lib/libc.so.1

How to repeat:
Run falcon_limit with the source code taken from mysql-6.0-falcon-team as of today.

Suggested fix:
Fix it so that Falcon do not access deleted memory.
[25 Mar 2009 13:39] Olav Sandstå
The cause for this failure is that Transaction::visible() is accessing a deleted Transaction object (see the parameter to Transaction::visible() in the call stack). 

Before pushing the new TransactionState object (see patch in bug#41357) this situation did not lead to a crash since Falcon only read data members from the Transaction object. But with the state having been moved to a separate object, it will now reference a pointer from the Transaction State object which is pointing to an illegal address. So the new Transaction State object has likely changed this situation from being reading of deleted data to accessing an illegal address.

The fix for this is to not use the Transaction object but only use the Transaction State object for this purpose.
[25 Mar 2009 13:48] 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/70362

3075 Olav Sandstaa	2009-03-25
      Fix for Bug#43858 falcon_limit crashes in Transaction::visible()
      
      To avoid crashing if the Transaction object is deleted use the Transaction State object instead
      when calling Transaction::visible().
     @ storage/falcon/RecordVersion.cpp
        Use the Transaction State object in stead of the Transaction object to avoid accessing 
        deleted memory and access illegal pointers.
[25 Mar 2009 14:14] Kevin Lewis
Olav, This patch should fix this bug.  OK to push.
[2 Apr 2009 17:39] Bugs System
Pushed into 6.0.11-alpha (revid:hky@sun.com-20090402144811-yc5kp8g0rjnhz7vy) (version source revid:jstarkey@mysql.com-20090325181754-f71kir7dokq8e7ao) (merge vers: 6.0.11-alpha) (pib:6)
[15 May 2009 16:09] MC Brown
Internal/test fix. No changelog entry required.