| Bug #36734 | Falcon crash in Record::getEncodedValue | ||
|---|---|---|---|
| Submitted: | 15 May 2008 10:27 | Modified: | 19 May 2009 7:00 |
| Reporter: | Alexey Stroganov | Email Updates: | |
| Status: | Duplicate | Impact on me: | |
| Category: | MySQL Server: Falcon storage engine | Severity: | S1 (Critical) |
| Version: | 6.0.6pre, 6.0.8pre, 6.0-falcon-team tree | OS: | Any |
| Assigned to: | Assigned Account | CPU Architecture: | Any |
| Tags: | F_TRANSACTION | ||
[15 May 2008 10:27]
Alexey Stroganov
[19 Jun 2008 13:28]
Alexey Stroganov
I observed a lot of server crashes while testing the laster 6.0.5 release with sysbench read-only test. Server crashes almost immediately after the beginning of the test. Crash is easily reproducible for optimized binary(backtrace is below) but it doesn't happen for debug one. I am still working on this issue trying to get bt for debug version.
bt:
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/data0/ranger/mysql-6.0.5-alpha-linux-x86_64-glibc23//bin/mysqld --no-defaults'.
Program terminated with signal 6, Aborted.
#0 0x00002b5f99d81fed in raise () from /lib64/libpthread.so.0
#0 0x00002b5f99d81fed in raise () from /lib64/libpthread.so.0
#1 0x0000000000818c6c in Error::error (string=<value optimized out>) at Error.cpp:92
#2 0x000000000083faf2 in Record::getEncodedValue (this=0x2aaae53a37d8, fieldId=<value optimized out>, value=0x4020c5d0)
at Record.cpp:648
#3 0x000000000083fc9b in Record::getRawValue (this=0x2aaae53a37d8, fieldId=9, value=0x4020c5d0) at Record.cpp:363
#4 0x00000000008406e9 in Record::getValue (this=0x45ec, fieldId=18124, value=0x6) at Record.cpp:315
#5 0x00000000007d0d1a in StorageTable::compareKey (this=0x2aaae248a3f0, key=<value optimized out>,
keyLength=<value optimized out>) at StorageTable.cpp:398
#6 0x00000000007c654e in StorageInterface::index_read (this=0x11a58c0, buf=0x11a5cb0 "\001", keyBytes=0x11e5c00 "\002",
key_len=2, find_flag=<value optimized out>) at ha_falcon.cpp:1345
#7 0x00000000006a9ff5 in join_read_always_key (tab=0x12e3ee0) at sql_select.cc:14026
#8 0x000000000069c947 in sub_select (join=0x11e3c78, join_tab=0x12e3ee0, end_of_records=6) at sql_select.cc:13336
#9 0x000000000069d28d in do_select (join=0x11e3c78, fields=0x11ea898, table=0x0, procedure=0x0) at sql_select.cc:13087
#10 0x00000000006b4cb4 in JOIN::exec (this=0x11e3c78) at sql_select.cc:2739
#11 0x00000000006b6850 in mysql_select (thd=0x11d9360, rref_pointer_array=0x11ea978, tables=0x11eb4c0, wild_num=0,
fields=@0x11ea898, conds=0x11ebee8, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0,
select_options=2417248768, result=0x11ec0e8, unit=0x11ea350, select_lex=0x11ea790) at sql_select.cc:2927
#12 0x00000000006b7234 in handle_select (thd=0x11d9360, lex=0x11ea2b0, result=0x11ec0e8, setup_tables_done_option=0)
at sql_select.cc:289
#13 0x000000000063d98c in execute_sqlcom_select (thd=0x11d9360, all_tables=0x11eb4c0) at sql_parse.cc:4745
#14 0x0000000000645e73 in mysql_execute_command (thd=0x11d9360) at sql_parse.cc:1971
#15 0x00000000006bfdda in Prepared_statement::execute (this=0x11e9fa0, expanded_query=0x4020e3e0, open_cursor=false)
at sql_prepare.cc:3132
#16 0x00000000006c2938 in mysql_stmt_execute (thd=0x11d9360,
packet_arg=0x11dbc4a "def\aphptest\aphptest\aphptest\bstate_id\bstate_id\f?", packet_length=15) at sql_prepare.cc:2365
#17 0x0000000000649f1d in dispatch_command (command=COM_SLEEP, thd=0x11d9360, packet=0x11dbc41 "", packet_length=15)
at sql_parse.cc:986
#18 0x000000000064a437 in do_command (thd=0x11d9360) at sql_parse.cc:723
#19 0x000000000063b704 in handle_one_connection (arg=0x11d9360) at sql_connect.cc:1134
#20 0x00002b5f99d7b193 in start_thread () from /lib64/libpthread.so.0
#21 0x00002b5f9a3ae45d in clone () from /lib64/libc.so.6
#22 0x0000000000000000 in ?? ()
[19 Aug 2008 19:51]
Christopher Powers
Reproduced with mysql-6.0-falcon-team as of Aug 19 2008 (revision 2789) running sysbench 0.5 pre-release:
26 Error::assertionFailed() ./storage/falcon/Error.cpp:78
25 Transaction::initialize() ./storage/falcon/Transaction.cpp:103
24 TransactionManager::startTransaction() ./storage/falcon/TransactionManager.cpp:122
23 Database::startTransaction() ./storage/falcon/Database.cpp:1236
22 Connection::getTransaction() ./storage/falcon/Connection.cpp:256
21 StorageDatabase::savepointSet() ./storage/falcon/StorageDatabase.cpp:509
20 StorageConnection::savepointSet() ./storage/falcon/StorageConnection.cpp:203
19 StorageConnection::markVerb() ./storage/falcon/StorageConnection.cpp:334
18 StorageInterface::external_lock() ./storage/falcon/ha_falcon.cpp:1931
17 handler::ha_external_lock() ./libmysqld/handler.cc:5274
16 lock_external() ./libmysqld/lock.cc:389
15 mysql_lock_tables() ./libmysqld/lock.cc:290
14 lock_tables() ./libmysqld/sql_base.cc:4407
13 open_and_lock_tables_derived() ./libmysqld/sql_base.cc:4112
12 open_and_lock_tables() ./client/mysql_priv.h:1615
11 execute_sqlcom_select() ./libmysqld/sql_parse.cc:4836
10 mysql_execute_command() ./libmysqld/sql_parse.cc:2107
9 Prepared_statement::execute() ./libmysqld/sql_prepare.cc:3571
8 Prepared_statement::execute_loop() ./libmysqld/sql_prepare.cc:3244
7 mysql_stmt_execute() ./libmysqld/sql_prepare.cc:2465
6 dispatch_command() ./libmysqld/sql_parse.cc:1075
5 do_command() ./libmysqld/sql_parse.cc:807
4 handle_one_connection() ./libmysqld/sql_connect.cc:1153
3 start_thread() 0x00002b22a6640020
void Transaction::initialize(Connection* cnct, TransId seq)
{
Sync sync(&syncObject, "Transaction::initialize(1)");
sync.lock(Exclusive);
ASSERT(savePoints == NULL);
ASSERT(freeSavePoints == NULL);
ASSERT(firstRecord == NULL);
>> ASSERT(dependencies == 0); <<<< dependencies == 1
connection = cnct;
[19 Aug 2008 20:43]
Kevin Lewis
Olav, This is related to 36410 in that an initializing transaction still had dependencies. It is not exactly a duplicate. but is caused by the same condition that dependencies are not atomically released before the transition to available.
[20 Aug 2008 13:57]
Olav Sandstå
The new call stack produced by Chris is the same as the call stack in bug 38739. This is the "next" bug you run into after the erroneous assert that showed up in 36410 and 35932 has been fixed (see patch check-in for bug 35932). But I am not sure if the original call stack reported in this bug is caused by the same problem as in bug 38739 so we should wait to declare this as a duplicate.
[27 Aug 2008 6:24]
Xuekun Hu
I met the same crash issue with the same call stack on dbt3 workload with high concurrent threads. I saw patch for bug#36410. So I tested again with mysql-6.0-falcon (revno 2779) version. The falcon crash was disappeared. dbt3 workload could be successfully run.
[23 Oct 2008 4:21]
Alexey Stroganov
Got the assertion with similar backtrace while testing the recent falcon tree with sysbench:
[Falcon] Error: assertion (vector[index] < size) failed at line 653 in file Record.cpp
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/data0/ranger/mysql-6.0.8-alpha-pb130-linux-x86_64/bin/mysqld --no-defaults --p'.
Program terminated with signal 6, Aborted.
#0 0x00002b0159d68fed in raise () from /lib64/libpthread.so.0
#0 0x00002b0159d68fed in raise () from /lib64/libpthread.so.0
#1 0x00000000008ea2e2 in Error::error (string=<value optimized out>) at Error.cpp:94
#2 0x0000000000913ab7 in Record::getEncodedValue (this=0x2aaafbd0a658, fieldId=<value optimized out>, value=0x409dd510)
at Record.cpp:653
#3 0x0000000000913c6b in Record::getRawValue (this=0x2aaafbd0a658, fieldId=9, value=0x409dd510) at Record.cpp:368
#4 0x00000000009146a9 in Record::getValue (this=0x2c5d, fieldId=11741, value=0x6) at Record.cpp:320
#5 0x00000000008a1f3d in StorageTable::compareKey (this=0x2aaae7330948, key=<value optimized out>,
keyLength=<value optimized out>) at StorageTable.cpp:437
#6 0x000000000089551b in StorageInterface::index_next_same (this=0x2aaae51b9f98, buf=0x2aaae51bd7b8 "�",
key=0x2aaae61e87c8 "\002", key_len=2) at ha_falcon.cpp:1715
#7 0x0000000000700a7f in join_read_next_same (info=<value optimized out>) at sql_select.cc:14476
#8 0x00000000006f2dfc in sub_select (join=0x1e3df78, join_tab=0x2aaae61e8528, end_of_records=<value optimized out>)
at sql_select.cc:13726
#9 0x00000000006f33b4 in do_select (join=0x1e3df78, fields=0x1e6e6b0, table=0x0, procedure=0x0) at sql_select.cc:13455
#10 0x000000000070ac55 in JOIN::exec (this=0x1e3df78) at sql_select.cc:2829
#11 0x000000000070c840 in mysql_select (thd=0x2aaae4e70a30, rref_pointer_array=0x1e6e790, tables=0x1e6f280, wild_num=0,
fields=@0x1e6e6b0, conds=0x1e6ff28, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0,
select_options=2416200192, result=0x1e700d0, unit=0x1e6e148, select_lex=0x1e6e5a8) at sql_select.cc:3019
#12 0x000000000070d219 in handle_select (thd=0x2aaae4e70a30, lex=0x1e6e0a8, result=0x1e700d0, setup_tables_done_option=0)
at sql_select.cc:301
#13 0x0000000000690c99 in execute_sqlcom_select (thd=0x2aaae4e70a30, all_tables=0x1e6f280) at sql_parse.cc:4644
#14 0x0000000000695ead in mysql_execute_command (thd=0x2aaae4e70a30) at sql_parse.cc:2064
#15 0x0000000000717ff8 in Prepared_statement::execute (this=0x1cfece0, expanded_query=<value optimized out>,
open_cursor=false) at sql_prepare.cc:3577
#16 0x000000000071a440 in Prepared_statement::execute_loop (this=0x1cfece0, expanded_query=0x409df3d0, open_cursor=false,
packet=<value optimized out>, packet_end=<value optimized out>) at sql_prepare.cc:3244
#17 0x000000000071a7dd in mysql_stmt_execute (thd=0x2aaae4e70a30, packet_arg=0x2aaae4e73421 "", packet_length=15)
at sql_prepare.cc:2465
#18 0x000000000069a59d in dispatch_command (command=COM_STMT_EXECUTE, thd=0x2aaae4e70a30, packet=0x2aaae4e73421 "",
packet_length=15) at sql_parse.cc:960
#19 0x000000000069aa86 in do_command (thd=0x2aaae4e70a30) at sql_parse.cc:689
#20 0x000000000068def4 in handle_one_connection (arg=0x2aaae4e70a30) at sql_connect.cc:1156
#21 0x00002b0159d62193 in start_thread () from /lib64/libpthread.so.0
#22 0x00002b015a39545d in clone () from /lib64/libc.so.6
#23 0x0000000000000000 in ?? ()
[5 Jan 2009 17:29]
Olav Sandstå
I have tried to reproduce the crash with the latest Falcon version (checked out from the falcon-team tree) using sysbench as described in the bug report without being able to reproduce any crash. I have run the sysbench test for several hours against both a debug and a non-debug build. Since this bug was reported Falcon has gotten a new implementation of the transaction dependency manager (see WL#4654). This should solve at least one of the crashes reported in this bug report and possibly also fix the original crash. Unless anyone else can reproduce it or have suggestions for how to reproduce the crash, I suggest we close this bug report based on that the problem is likely fixed by the new dependency manager.
[18 Mar 2009 17:36]
Alexey Stroganov
Olav, Please take a look at the very last stack trace in BUG#38375 observed by Wlad on Windows for the latest 6.0-falcon-team tree. Although query that caused this issue is different stack trace looks very very similar. I've changed state of the bug to Analyzing. Please updated it after evaluation of stack trace from BUG#38375.
[19 May 2009 7:00]
Olav Sandstå
Hi Alexey, I have looked at the latest call stack in BUG#38375. You are right that this is similar to the call stack in this bug report. It seems like an assert that there are several causes for happening and that later changes have made it appear again. There is another bug with a fix for this crash: Bug#42131. I have also opened a new bug report for a more recent re-appear of a similar crash with the same call stack, see Bug#44946. I am closing this bug as believed to be a duplicate of Bug#42131.
