Bug #36410 Falcon crashes on 64 concurrent threads
Submitted: 29 Apr 2008 19:14 Modified: 15 May 2009 12:50
Reporter: Vadim TKACHENKO Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S2 (Serious)
Version:6.0.6-alpha ChangeSet@1.2650.1.1, 2008-04-27 03:34:10+02:00 OS:Linux
Assigned to: Olav Sandstå CPU Architecture:Any
Triage: D2 (Serious)

[29 Apr 2008 19:14] Vadim TKACHENKO
Description:
I did some benchmarks and Falcon crashed under load with 64 threads:

Version: '6.0.6-alpha'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution                                                  
080429 12:03:57 - mysqld got signal 6 ;                                                                                             
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=8388600                                                                                                             
read_buffer_size=131072                                                                                                             
max_used_connections=256                                                                                                            
max_threads=3000                                                                                                                    
thread_count=64                                                                                                                     
connection_count=64                                                                                                                 
It is possible that mysqld could use up to                                                                                          
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 614801 K                                                      
bytes of memory                                                                                                                     
Hope that's ok; if not, decrease some variables in the equation.                                                                    
                                                                                                                                    
thd: 0x2aab243f21c0                                                                                                                 
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...                                                                                                                   
/mnt/data/falcon/bin/libexec/mysqld(print_stacktrace+0x1e) [0x725e0e]                                                               
/mnt/data/falcon/bin/libexec/mysqld(handle_segfault+0x33b) [0x5ebe8b]                                                               
/lib64/libpthread.so.0 [0x3b68e0de70]                                                                                               
/lib64/libpthread.so.0(raise+0x2d) [0x3b68e0dd4d]                                                                                   
/mnt/data/falcon/bin/libexec/mysqld(Error::error(char const*, ...)+0xec) [0x7bf1ac]                                                 
/mnt/data/falcon/bin/libexec/mysqld(Transaction::commitNoUpdates()+0x1bb) [0x78f94b]                                                
/mnt/data/falcon/bin/libexec/mysqld(Transaction::commit()+0xb3) [0x78fb43]                                                          
/mnt/data/falcon/bin/libexec/mysqld(Connection::commit()+0x51) [0x7a6c61]                                                           
/mnt/data/falcon/bin/libexec/mysqld(StorageConnection::commit()+0x4b) [0x7715cb]                                                    
/mnt/data/falcon/bin/libexec/mysqld(StorageInterface::external_lock(THD*, int)+0x262) [0x76e512]                                    
/mnt/data/falcon/bin/libexec/mysqld(handler::ha_external_lock(THD*, int)+0x1a) [0x6d6e9a]                                           
/mnt/data/falcon/bin/libexec/mysqld(mysql_unlock_tables(THD*, st_mysql_lock*)+0x61) [0x5e5b31]                                      
/mnt/data/falcon/bin/libexec/mysqld(select_send::send_eof()+0x22) [0x5d7922]                                                        
/mnt/data/falcon/bin/libexec/mysqld [0x65b272]                                                                                      
/mnt/data/falcon/bin/libexec/mysqld(JOIN::exec()+0x8f3) [0x66e373]                                                                  
/mnt/data/falcon/bin/libexec/mysqld(mysql_select(THD*, Item***, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_orde
r*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*)+0x1b0) [0x66ff20]         
/mnt/data/falcon/bin/libexec/mysqld(handle_select(THD*, st_lex*, select_result*, unsigned long)+0x174) [0x670904]                   
/mnt/data/falcon/bin/libexec/mysqld [0x5f6d3c]                                                                                      
/mnt/data/falcon/bin/libexec/mysqld(mysql_execute_command(THD*)+0x4506) [0x5fea36]                                                  
/mnt/data/falcon/bin/libexec/mysqld(Prepared_statement::execute(String*, bool)+0x3aa) [0x67914a]                                    
/mnt/data/falcon/bin/libexec/mysqld(mysql_stmt_execute(THD*, char*, unsigned int)+0x398) [0x6794f8]                                 
/mnt/data/falcon/bin/libexec/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x468) [0x6020c8]              
/mnt/data/falcon/bin/libexec/mysqld(do_command(THD*)+0xc7) [0x603127]                                                               
/mnt/data/falcon/bin/libexec/mysqld(handle_one_connection+0xf4) [0x5f43f4]                                                          
/lib64/libpthread.so.0 [0x3b68e062f7]                                                                                               
/lib64/libc.so.6(clone+0x6d) [0x3b682ce85d]                                                                                         
Trying to get some variables.                                                                                                       
Some pointers may be invalid and cause the dump to abort...                                                                         
thd->query at 0x10bd58f0 = SELECT name FROM sbtest WHERE country_id = ? limit 5                                                     
thd->thread_id=4201                                                                                                                 
thd->killed=NOT_KILLED   

How to repeat:

Table structure is 
CREATE TABLE `sbtest` (
  `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `name` varchar(64) NOT NULL DEFAULT '',
  `email` varchar(64) NOT NULL DEFAULT '',
  `password` varchar(64) NOT NULL DEFAULT '',
  `dob` date DEFAULT NULL,
  `address` varchar(128) NOT NULL DEFAULT '',
  `city` varchar(64) NOT NULL DEFAULT '',
  `state_id` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `zip` varchar(8) NOT NULL DEFAULT '',
  `country_id` smallint(5) unsigned NOT NULL DEFAULT '0',
  PRIMARY KEY (`id`),
  KEY `email_idx` (`email`),
  KEY `country_id_idx` (`country_id`,`state_id`,`city`)
) ENGINE=Falcon AUTO_INCREMENT=1000001 DEFAULT CHARSET=latin1 MAX_ROWS=1000000

Queries are 
SELECT name FROM sbtest WHERE country_id = ? limit 5                          

where ? is random
[29 Apr 2008 22:22] Kevin Lewis
This problem was found in Transaction::commitNoUpdates and were tracked by three different bugs;
Bug#34602 and Bug#35932 are identical this bug.
Bug#36296 is a performance problem related it.

All were fixed with this changeset.

ChangeSet@1.2639.1.1, 2008-04-24 13:26:34-04:00, jas@rowvwade. +4 -0
  Changed the way dependencies are handled when committed a transaction 
  without updates.  Rather than trying to resolve unavoidable races
  conditions releasing other transaction's
[30 Apr 2008 3:19] Vadim TKACHENKO
ChangeSet@1.2634, 2008-04-20 is the latest at the moment available in BitKeeper
[30 Apr 2008 6:40] Hakan Küçükyılmaz
Vadim, yes the main tree is from 20th April. Until we merge with main tree, can you please try mysql-6.0-falcon tree? It should be available via bkbits as well.

http://mysql.bkbits.net:8080/mysql-6.0-falcon
[30 Apr 2008 6:44] Vadim TKACHENKO
Hakan,

Perfect, I will try
[30 Apr 2008 7:24] Vadim TKACHENKO
I tried latest CS from mysql-6.0-falcon tree.

Actually now it crashes even much faster and with 4 threads

Version: '6.0.6-alpha'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution
080430  0:19:46 - mysqld got signal 6 ;
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=8388600
read_buffer_size=131072
max_used_connections=4
max_threads=3000
thread_count=4
connection_count=4
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 614801 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x53f27b0
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...
/mnt/data/falcon/bin/libexec/mysqld(print_stacktrace+0x1e) [0x7263be]
/mnt/data/falcon/bin/libexec/mysqld(handle_segfault+0x33b) [0x5ec41b]
/lib64/libpthread.so.0 [0x3b68e0de70]
/lib64/libpthread.so.0(raise+0x2d) [0x3b68e0dd4d]
/mnt/data/falcon/bin/libexec/mysqld(Error::error(char const*, ...)+0xec) [0x7bfc8c]
/mnt/data/falcon/bin/libexec/mysqld(Transaction::releaseDependencies()+0xc2) [0x78fef2]
/mnt/data/falcon/bin/libexec/mysqld(Transaction::commitNoUpdates()+0x125) [0x790415]
/mnt/data/falcon/bin/libexec/mysqld(Transaction::commit()+0xb3) [0x790623]
/mnt/data/falcon/bin/libexec/mysqld(Connection::commit()+0x51) [0x7a7741]
/mnt/data/falcon/bin/libexec/mysqld(StorageConnection::commit()+0x4b) [0x7720fb]
/mnt/data/falcon/bin/libexec/mysqld(StorageInterface::external_lock(THD*, int)+0x262) [0x76ee02]
/mnt/data/falcon/bin/libexec/mysqld(handler::ha_external_lock(THD*, int)+0x1a) [0x6d742a]
/mnt/data/falcon/bin/libexec/mysqld(mysql_unlock_tables(THD*, st_mysql_lock*)+0x61) [0x5e60c1]
/mnt/data/falcon/bin/libexec/mysqld(select_send::send_eof()+0x22) [0x5d7eb2]
/mnt/data/falcon/bin/libexec/mysqld [0x65b802]
/mnt/data/falcon/bin/libexec/mysqld(JOIN::exec()+0x8f3) [0x66e903]
/mnt/data/falcon/bin/libexec/mysqld(mysql_select(THD*, Item***, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*)+0x1b0) [0x6704b0]
/mnt/data/falcon/bin/libexec/mysqld(handle_select(THD*, st_lex*, select_result*, unsigned long)+0x174) [0x670e94]
/mnt/data/falcon/bin/libexec/mysqld [0x5f72cc]
/mnt/data/falcon/bin/libexec/mysqld(mysql_execute_command(THD*)+0x4506) [0x5fefc6]
/mnt/data/falcon/bin/libexec/mysqld(Prepared_statement::execute(String*, bool)+0x3aa) [0x6796da]
/mnt/data/falcon/bin/libexec/mysqld(mysql_stmt_execute(THD*, char*, unsigned int)+0x398) [0x679a88]
/mnt/data/falcon/bin/libexec/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x468) [0x602658]
/mnt/data/falcon/bin/libexec/mysqld(do_command(THD*)+0xc7) [0x6036b7]
/mnt/data/falcon/bin/libexec/mysqld(handle_one_connection+0xf4) [0x5f4984]
/lib64/libpthread.so.0 [0x3b68e062f7]
/lib64/libc.so.6(clone+0x6d) [0x3b682ce85d]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x5485a60 = SELECT name FROM sbtest WHERE id = ?
thd->thread_id=5
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.
[30 Apr 2008 16:33] Alexey Stroganov
I've run this query for server built from the latest sources of mysql-6.0-falcon-team tree ('6.0.6-alpha-pb295') and in my case server crashes with 256 threads but backtrace looks differently. Unfortunately there is no debug binary in pushbuild package so I am going to rebuild from sources with debug and will update issue with my findings.

(gdb) bt
#0  0x00002b4b5b372fed in raise () from /lib64/libpthread.so.0
#1  0x000000000088263c in Error::error (string=<value optimized out>) at Error.cpp:92
#2  0x00000000008a9802 in Record::getEncodedValue (this=0x2aaae88f9f90, fieldId=<value optimized out>, value=0x416285b0)
    at Record.cpp:653
#3  0x00000000008a99b4 in Record::getRawValue (this=0x2aaae88f9f90, fieldId=9, value=0x416285b0) at Record.cpp:368
#4  0x00000000008aa409 in Record::getValue (this=0x2314, fieldId=9598, value=0x6) at Record.cpp:320
#5  0x000000000083a8fa in StorageTable::compareKey (this=0x2aaae5d90d18, key=<value optimized out>,
    keyLength=<value optimized out>) at StorageTable.cpp:409
#6  0x000000000082fd06 in StorageInterface::index_read (this=0x17bdf60, buf=0x17439c0 "\001", keyBytes=0x1f559f0 "\002",
    key_len=2, find_flag=<value optimized out>) at ha_falcon.cpp:1335
#7  0x00000000006e9b25 in join_read_always_key (tab=0x2aaae3c47c68) at sql_select.cc:14026
#8  0x00000000006dc467 in sub_select (join=0x1f53a68, join_tab=dwarf2_read_address: Corrupted DWARF expression.
) at sql_select.cc:13336
#9  0x00000000006dcdad in do_select (join=0x1f53a68, fields=0x1f56368, table=0x0, procedure=0x0) at sql_select.cc:13087
#10 0x00000000006f47f3 in JOIN::exec (this=0x1f53a68) at sql_select.cc:2739
#11 0x00000000006f63a0 in mysql_select (thd=0x2aaae5a9cc30, rref_pointer_array=0x1f56448, tables=0x1f5af08, wild_num=0,
    fields=@0x1f56368, conds=0x1f5b930, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0,
    select_options=2417248768, result=0x1f5bb30, unit=0x1f55e20, select_lex=0x1f56260) at sql_select.cc:2927
#12 0x00000000006f6d84 in handle_select (thd=0x2aaae5a9cc30, lex=0x1f55d80, result=0x1f5bb30, setup_tables_done_option=0)
    at sql_select.cc:289
#13 0x000000000067ccbc in execute_sqlcom_select (thd=0x2aaae5a9cc30, all_tables=0x1f5af08) at sql_parse.cc:4796
#14 0x0000000000684a36 in mysql_execute_command (thd=0x2aaae5a9cc30) at sql_parse.cc:1995
#15 0x00000000006ff68a in Prepared_statement::execute (this=0x1f55a70, expanded_query=0x4162a3d0, open_cursor=false)
    at sql_prepare.cc:3147
#16 0x00000000006ffa38 in mysql_stmt_execute (thd=0x2aaae5a9cc30,
    packet_arg=0x2aaae5a9fb1a "def\aphptest\aphptest\aphptest\004name\004name\f\b", packet_length=15) at sql_prepare.cc:2373
#17 0x0000000000688108 in dispatch_command (command=COM_STMT_EXECUTE, thd=0x2aaae5a9cc30, packet=<value optimized out>,
    packet_length=15) at sql_parse.cc:1000
#18 0x0000000000689167 in do_command (thd=0x2aaae5a9cc30) at sql_parse.cc:722
#19 0x000000000067a374 in handle_one_connection (arg=0x2aaae5a9cc30) at sql_connect.cc:1134
#20 0x00002b4b5b36c193 in start_thread () from /lib64/libpthread.so.0
#21 0x00002b4b5b99f45d in clone () from /lib64/libc.so.6
#22 0x0000000000000000 in ?? ()
[30 Apr 2008 17:18] Alexey Stroganov
Just rebuilt server from sources with debug. Version: '6.0.6-alpha-pb295-debug'. It crashes with only 4 threads with following backtrace:

(gdb) bt
#0  0x00002b57640bdfed in raise () from /lib64/libpthread.so.0
#1  0x00000000009bc054 in Error::debugBreak () at Error.cpp:92
#2  0x00000000009bc168 in Error::error (string=0xe7f168 "assertion failed at line %d in file %s\n") at Error.cpp:69
#3  0x00000000009bc1ff in Error::assertionFailed (fileName=0xe84780 "Record.cpp", line=653) at Error.cpp:76
#4  0x00000000009f2b40 in Record::getEncodedValue (this=0x2aaae4f6a050, fieldId=9, value=0x4588bb90) at Record.cpp:653
#5  0x00000000009f3ae9 in Record::getRawValue (this=0x2aaae4f6a050, fieldId=9, value=0x4588bb90) at Record.cpp:368
#6  0x00000000009f3e6b in Record::getValue (this=0x2aaae4f6a050, fieldId=9, value=0x4588bb90) at Record.cpp:320
#7  0x00000000009643a8 in StorageTable::compareKey (this=0x2aaae24964c8, key=0x15f0b58 "\002", keyLength=2)
    at StorageTable.cpp:409
#8  0x0000000000950872 in StorageInterface::index_read (this=0x15e41c8, buf=0x15e45c8 "�", keyBytes=0x15f0b58 "\002",
    key_len=2, find_flag=HA_READ_KEY_EXACT) at ha_falcon.cpp:1335
#9  0x000000000082a042 in handler::index_read_map (this=0x15e41c8, buf=0x15e45c8 "�", key=0x15f0b58 "\002", keypart_map=1,
    find_flag=HA_READ_KEY_EXACT) at ../../sql/handler.h:1656
#10 0x000000000075f301 in join_read_always_key (tab=0x1610290) at sql_select.cc:14026
#11 0x00000000007626cd in sub_select (join=0x15eebd0, join_tab=0x1610290, end_of_records=false) at sql_select.cc:13336
#12 0x000000000076a458 in do_select (join=0x15eebd0, fields=0x15ff988, table=0x0, procedure=0x0) at sql_select.cc:13087
#13 0x00000000007885ef in JOIN::exec (this=0x15eebd0) at sql_select.cc:2739
#14 0x00000000007835fb in mysql_select (thd=0x15dc0b8, rref_pointer_array=0x15ffa68, tables=0x16005c0, wild_num=0,
    fields=@0x15ff988, conds=0x1600fe8, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0,
    select_options=2417248768, result=0x16011e8, unit=0x15ff440, select_lex=0x15ff880) at sql_select.cc:2927
#15 0x0000000000788918 in handle_select (thd=0x15dc0b8, lex=0x15ff3a0, result=0x16011e8, setup_tables_done_option=0)
    at sql_select.cc:289
#16 0x00000000006f3986 in execute_sqlcom_select (thd=0x15dc0b8, all_tables=0x16005c0) at sql_parse.cc:4796
#17 0x00000000006f4dee in mysql_execute_command (thd=0x15dc0b8) at sql_parse.cc:1995
#18 0x000000000079a9d3 in Prepared_statement::execute (this=0x15ff088, expanded_query=0x4588d770, open_cursor=false)
    at sql_prepare.cc:3147
#19 0x000000000079b040 in mysql_stmt_execute (thd=0x15dc0b8, packet_arg=0x15df509 "", packet_length=15)
    at sql_prepare.cc:2373
#20 0x00000000006fdfea in dispatch_command (command=COM_STMT_EXECUTE, thd=0x15dc0b8, packet=0x15df509 "", packet_length=15)
    at sql_parse.cc:1000
#21 0x00000000006ff5b7 in do_command (thd=0x15dc0b8) at sql_parse.cc:722
#22 0x00000000006ebce6 in handle_one_connection (arg=0x15dc0b8) at sql_connect.cc:1134
#23 0x00002b57640b7193 in start_thread () from /lib64/libpthread.so.0
#24 0x00002b576490345d in clone () from /lib64/libc.so.6
#25 0x0000000000000000 in ?? ()
[5 May 2008 14:18] Kevin Lewis
This crash is a duplicate of Bug#34602 The assertion is ASSERT(dependencies == 0);
It occurs right after a loop of 10 tries to release these dependencies.
This loop was fixed and pushed by Jim into mysql-6.0-falcon-team but not pushed to 6.0.5 release clone-off.
[5 May 2008 19:43] Alexey Stroganov
Just rechecked with the latest changes in mysql-6.0-falcon-team tree. Issue still exists.

And actually assert is not the same that was mentioned in the previous comment:

#4  0x00000000009f64b8 in Record::getEncodedValue (this=0x2aaae4b32f48, fieldId=9, value=0x45849b90) at Record.cpp:653
653                             ASSERT(vector[index] < size);

So I changed state of the bug back to Verified.
[7 May 2008 16:15] Philip Stoev
Alexey: you are getting a crash in getEncodedValue , whereas Kevin appears to be talking about the crash in commitNoUpdates(). Maybe the getEncodedValue() should be split into a separate bug?
[7 May 2008 16:26] Vadim TKACHENKO
Please note this crash happens not in commitNoUpdates like in Bug#34602, but
in releaseDependencies.
I assume 34602 and this bug are different.
[7 May 2008 17:01] Kevin Lewis
This bug was originally opened by Vadim about an assert in commitNoUpdates.  That assert is no longer there, due to the fix for Bug#34602 .  But Vadim indicates that he now sees an assert in Transaction::releaseDependencies(). This may be a related to that fix, and is appropriate to keep associated with this Bug.

The assert in Record::getEncodedValue() that Ranger has reported is different.  It should be put into a new bug.  This is however similar to the fix for Bug#36097.  That fix is in mysql-6.0-falcon-team, but not iun the 6.0.5 release binaries.  Ranger, can you confirm that your crash in getEncodedValue() still exists in falcon-team?  If so, please open a new bug.

Vadim, Due to the confusion, it would be good to re-submit the steps to reproduce the bug in Transaction::releaseDependencies(). If you can provide another call stack with line numbers, that would help since releaseDependencies() has more than one assert.  Also, please provide the value of the variables involved in the assert.
[7 May 2008 19:52] Vadim TKACHENKO
Kevin,

The steps are exactly the same I described originally in this bug.
I am not sure how to get another stack than I posted here - what are steps for ?

I am not able to make more experiments this week, maybe next one.
[7 May 2008 20:53] Kevin Lewis
Vadim,  We can try to reproduce it, but you have only provided a create table and a select statement.  We need some raw data to import into the table or some code to generate that table.  Also, how many of these select statements were you running concurrently?
[7 May 2008 22:58] Vadim TKACHENKO
Kevin,

The schema is
   1.
      CREATE TABLE IF NOT EXISTS `$tableName` (
   2.
          `id` int(10) UNSIGNED NOT NULL AUTO_INCREMENT,
   3.
          `name` varchar(64) NOT NULL DEFAULT '',
   4.
          `email` varchar(64) NOT NULL DEFAULT '',
   5.
          `password` varchar(64) NOT NULL DEFAULT '',
   6.
          `dob` date DEFAULT NULL,
   7.
          `address` varchar(128) NOT NULL DEFAULT '',
   8.
          `city` varchar(64) NOT NULL DEFAULT '',
   9.
          `state_id` tinyint(3) UNSIGNED NOT NULL DEFAULT '0',
  10.
          `zip` varchar(8) NOT NULL DEFAULT '',
  11.
          `country_id` smallint(5) UNSIGNED NOT NULL DEFAULT '0',
  12.
          PRIMARY KEY  (`id`),
  13.
          UNIQUE KEY `email` (`email`),
  14.
          KEY `country_id` (`country_id`,`state_id`,`city`)
  15.
          )

Queries just  SELECT name FROM sbtest WHERE id = ?

so it just access by primary key, which is autoincrement, I think you can use just random data for other fields.

I got crash with 4 concurrent threads on my 8-core box.
[15 May 2008 10:30] Alexey Stroganov
I reported crash in Record::getEncodedValue as BUG#36734
[21 May 2008 17:07] Kevin Lewis
Jim pushed a change which may fix this crash in releaseDependency;

ChangeSet@1.2670.3.3, 2008-05-21 10:58:08-04:00, jas@pendragon. +4 -0
  Do some quick fixes for race conditions.
[31 May 2008 23:55] Vadim TKACHENKO
Tried ChangeSet@1.2690, 2008-05-29 23:51:15+02:00, hakank@lu0011.(none) +2 -0
  Moved failing test case, see also Bug 37078.
from mysql-6.0-falcon tree.

Still have crash

080531  8:53:19 [Note] /usr/local/mysql-6.0-falcon/libexec/mysqld: ready for connections.
Version: '6.0.6-alpha'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution
[Falcon] Error: assertion (transaction->transactionId == state->transactionId || transaction->state == Available) failed at line 776 in file Transaction.cpp

080531 10:01:51 - mysqld got signal 6 ;
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=8388600
read_buffer_size=131072
max_used_connections=64
max_threads=3000
thread_count=16
connection_count=16
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 615059 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x2aab14052e10
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...
/usr/local/mysql-6.0-falcon/libexec/mysqld(print_stacktrace+0x1e) [0x72a14e]
/usr/local/mysql-6.0-falcon/libexec/mysqld(handle_segfault+0x33b) [0x5ee00b]
/lib64/libpthread.so.0 [0x3b68e0de70]
/lib64/libpthread.so.0(raise+0x2d) [0x3b68e0dd4d]
/usr/local/mysql-6.0-falcon/libexec/mysqld(Error::error(char const*, ...)+0x102) [0x7c4392]
/usr/local/mysql-6.0-falcon/libexec/mysqld(Transaction::releaseDependencies()+0xc5) [0x7944d5]
/usr/local/mysql-6.0-falcon/libexec/mysqld(Transaction::commitNoUpdates()+0x123) [0x7949f3]
/usr/local/mysql-6.0-falcon/libexec/mysqld(Transaction::commit()+0xb8) [0x794c08]
/usr/local/mysql-6.0-falcon/libexec/mysqld(Connection::commit()+0x56) [0x7abc76]
/usr/local/mysql-6.0-falcon/libexec/mysqld(StorageConnection::commit()+0x4b) [0x77609b]
/usr/local/mysql-6.0-falcon/libexec/mysqld(StorageInterface::external_lock(THD*, int)+0x25e) [0x772f2e]
/usr/local/mysql-6.0-falcon/libexec/mysqld(handler::ha_external_lock(THD*, int)+0x1a) [0x6dc11a]
/usr/local/mysql-6.0-falcon/libexec/mysqld(mysql_unlock_tables(THD*, st_mysql_lock*)+0x61) [0x5e7ca1]
/usr/local/mysql-6.0-falcon/libexec/mysqld(select_send::send_eof()+0x22) [0x5d9ab2]
/usr/local/mysql-6.0-falcon/libexec/mysqld [0x659ad1]
/usr/local/mysql-6.0-falcon/libexec/mysqld(JOIN::exec()+0x8e4) [0x670f54]
/usr/local/mysql-6.0-falcon/libexec/mysqld(mysql_select(THD*, Item***, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*)+0x1b0) [0x672b10]
/usr/local/mysql-6.0-falcon/libexec/mysqld(handle_select(THD*, st_lex*, select_result*, unsigned long)+0x169) [0x6734e9]
/usr/local/mysql-6.0-falcon/libexec/mysqld [0x5f8f67]
/usr/local/mysql-6.0-falcon/libexec/mysqld(mysql_execute_command(THD*)+0x302a) [0x5ff5ea]
/usr/local/mysql-6.0-falcon/libexec/mysqld(Prepared_statement::execute(String*, bool)+0x381) [0x67dfa1]
/usr/local/mysql-6.0-falcon/libexec/mysqld(Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*)+0x80) [0x680310]
/usr/local/mysql-6.0-falcon/libexec/mysqld(mysql_stmt_execute(THD*, char*, unsigned int)+0x19d) [0x6806ad]
/usr/local/mysql-6.0-falcon/libexec/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x498) [0x604148]
/usr/local/mysql-6.0-falcon/libexec/mysqld(do_command(THD*)+0xc7) [0x605067]
/usr/local/mysql-6.0-falcon/libexec/mysqld(handle_one_connection+0xf4) [0x5f6574]
/lib64/libpthread.so.0 [0x3b68e062f7]
/lib64/libc.so.6(clone+0x6d) [0x3b682ce85d]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x2aab10026208  is invalid pointer
thd->thread_id=712
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.
Fatal signal 11 while backtracing
[4 Jun 2008 12:31] Hakan Küçükyılmaz
Olav sees the same stack trace in Bug#35932.
[19 Jun 2008 13:23] 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  0x00002ab1e16f8fed in raise () from /lib64/libpthread.so.0
#0  0x00002ab1e16f8fed in raise () from /lib64/libpthread.so.0
#1  0x0000000000818c6c in Error::error (string=<value optimized out>) at Error.cpp:92
#2  0x00000000007e91cb in Transaction::commitNoUpdates (this=0x2aaae24cc398) at Transaction.cpp:369
#3  0x00000000007e93ba in Transaction::commit (this=0x2aaae24cc398) at Transaction.cpp:243
#4  0x0000000000800611 in Connection::commit (this=0x2aaaab6a9868) at Connection.cpp:269
#5  0x00000000007cae2b in StorageConnection::commit (this=0x2aaaab6a97d8) at StorageConnection.cpp:146
#6  0x00000000007c760d in StorageInterface::commit (hton=<value optimized out>, thd=0x2aaae3c92350, all=true)
    at ha_falcon.cpp:1151
#7  0x0000000000720dbe in ha_commit_one_phase (thd=0x2aaae3c92350, all=true) at handler.cc:1168
#8  0x0000000000720ff5 in ha_commit_trans (thd=0x2aaae3c92350, all=true) at handler.cc:1137
#9  0x0000000000641651 in end_trans (thd=0x5ec1, completion=COMMIT) at sql_parse.cc:580
#10 0x0000000000641e81 in mysql_execute_command (thd=0x2aaae3c92350) at sql_parse.cc:3798
#11 0x00000000006bfdda in Prepared_statement::execute (this=0x191c3f0, expanded_query=0x40cc13e0, open_cursor=false)
    at sql_prepare.cc:3132
#12 0x00000000006c2938 in mysql_stmt_execute (thd=0x2aaae3c92350, packet_arg=0x2aaae3c94c31 "\002", packet_length=9)
    at sql_prepare.cc:2365
#13 0x0000000000649f1d in dispatch_command (command=COM_SLEEP, thd=0x2aaae3c92350, packet=0x2aaae3c94c31 "\002",
    packet_length=9) at sql_parse.cc:986
#14 0x000000000064a437 in do_command (thd=0x2aaae3c92350) at sql_parse.cc:723
#15 0x000000000063b704 in handle_one_connection (arg=0x2aaae3c92350) at sql_connect.cc:1134
#16 0x00002ab1e16f2193 in start_thread () from /lib64/libpthread.so.0
#17 0x00002ab1e1d2545d in clone () from /lib64/libc.so.6
#18 0x0000000000000000 in ?? ()
[26 Jun 2008 0:24] Kevin Lewis
Olav,  Probably the same as Bug #35932 - Falcon crashes in Transaction::commitNoUpdates for simple SELECT queries
[13 Aug 2008 12:30] Olav Sandstå
As an initial fix to bug Bug #35932 "Falcon crashes in Transaction::commitNoUpdates for simple SELECT queries" I have committed the following patch:

http://lists.mysql.com/commits/51417
  
   "Changed the failing assert so that it handles that the transition of the Transaction object from Active to Available is not "atomic" when seen from a thread not having locked the transaction object."

This fix should also help on this issue.

Note that during work on #35932 I have also seen two different crash and hang scenarios:

Bug #38739 Assert in Transaction::initialize during simple SELECT quries
Bug #38748 Deadlock in Falcon when running simple SELECT queries

These two bugs are likely to occur also for the load used for producing this bug report.
[15 Aug 2008 7:15] Olav Sandstå
An updated patch for fixing the assert error in bug #35932 has been committed. The patch is available here:

  http://lists.mysql.com/commits/51622

      Follow-up fix to Bug#35932 Falcon crashes in Transaction::commitNoUpdates for simple SELECT queries
            
      The initial assert added in commit http://lists.mysql.com/commits/51491 was too strict. Change this to only assert if the state of the transaction the dependency is pointing to is Initializing.
[27 Aug 2008 6:16] Xuekun Hu
I met the same call stack with sysbench oltp simple test with older mysql 6.0 version. Now I tested again at mysql-6.0-faclon (revno 2779) version on three different machines (all are quad-core 2-socket system).  The crash seems like to be disappeared, but a new scene is happened. On one machine, sysbench oltp simple test works fine, whatever with low or high concurrent threads runnings. However on other two machines, with higher concurrent threads, mysql will restart automaticly, without any error messages, no call stack. You can only see the below message on the screen. 

"./bin/mysqld_safe: line 133:  6866 Aborted                 nohup /home/mysql/mysql/libexec/mysqld --basedir=/home/mysql/mysql/ --datadir=/home/mysql/database/var --user=mysql --skip-grant-tables --max_connections=3000 --table_cache=10240 --log-error=/home/mysql/database/var/perf-alcolu.err --pid-file=/home/mysql/database/var/perf-alcolu.pid --socket=/tmp/mysql.sock --port=3306 </dev/null >>/home/mysql/database/var/perf-alcolu.err 2>&1 >>/home/mysql/database/var/perf-alcolu.err 2>&1"
[28 Aug 2008 22:51] Kevin Lewis
This bug is 'fixed' by changing the assert so that it accounts for known concurrency issues in commitNoUpdates.  This patch also fixes Bug#35932.

There is a follow-on assert tracked by Bug#38739 that can still happen.  The concurrency problems with releasing dependencies will be fixed by a re-implementation of transaction dependencies, which will be done under Bug#38739.
[18 Sep 2008 11:03] Kevin Lewis
Olav wrote;  I agree that the bug should be moved away from "patch pending" since it there is no patch waiting for review. The patch I made for this problem was committed as part of bug 35932. So given that that patch have been pushed and is in 6.0.7 I think we should move this bug to the same state. I think we should consider this problem hopefully solved. New bug reports in this area will hopefully be bug 38739.
[4 Oct 2008 15:41] Jon Stephens
For changelog entry, see Bug #35932.
[25 Jan 2009 1:02] Vadim TKACHENKO
I experience the same problem in 6.0.9-alpha

stack trace attached
[25 Jan 2009 1:03] Vadim TKACHENKO
stack trace for 6.0.9

Attachment: stack.txt (text/plain), 8.10 KiB.

[13 Feb 2009 8:42] Olav Sandstå
Hi Vadim,

Thanks for the feedback about that you still saw this crash in 6.0.9. I have made a total new implementation of how Falcon handles transaction dependencies. This is implemented as part of WL#4654 (http://forge.mysql.com/worklog/task.php?id=4654). This code will be included in 6.0.10-alpha. 

If you want to try out the latest version you should be able to get it by downloading the latest source from either the mysql-6.0 or mysql-6.0-falcon trees on launchpad.

Since I believe this crash should not happen any more with the new dependency manager I will set the status of the bug back to as fixed in 6.0.10. Please let us know if you see it or any related problems again.
[15 May 2009 12:50] MC Brown
A note has been added to the 6.0.10 changelog: 

The internal dependency mechanism for handling records and transactions within Falcon has been updated. This fixes a number of issues with transactions and concurrent workloads within Falcon tables.