Bug #39901 Falcon crash when runing DBT2 with Stored Procedure enabled
Submitted: 7 Oct 2008 8:53 Modified: 5 May 2009 13:09
Reporter: Xuekun Hu Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S2 (Serious)
Version:6.0-falcon OS:Linux (SLES10SP1(2.6.16.46-0.12-smp))
Assigned to: Hakan Küçükyılmaz CPU Architecture:Any
Tags: DBT2, F_LIMIT

[7 Oct 2008 8:53] Xuekun Hu
Description:
Falcon crash when running DBT2 with SP enabled at the Stage 2, starting up driver. While not with DBT2 SP disabled.

The core stack are: 

/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(my_print_stacktrace+0x2e)[0x9ac93e]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(handle_segfault+0x33b)[0x6090eb]
/lib64/libpthread.so.0[0x2b711a093e70]
/lib64/libpthread.so.0(raise+0x2d)[0x2b711a093d4d]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN5Error5errorEPKcz+0xef)[0x825ebf]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN9WalkIndex11getNextNodeEv+0x177)[0x895ae7]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN9WalkIndex7getNextEb+0x18)[0x895bd8]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN15StorageDatabase11nextIndexedEP12StorageTableP11IndexWalkerb+0x24)[0x7da064]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN16StorageInterface10index_nextEPh+0x9f)[0x7d54ff]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN16StorageInterface10index_readEPhPKhj16ha_rkey_function+0xd3)[0x7d36f3]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld[0x67f795]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x1a8)[0x677a88]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld[0x677f3d]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN4JOIN4execEv+0x8f3)[0x68cc33]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x1b0)[0x68e810]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_Z13handle_selectP3THDP6st_lexP13select_resultm+0x169)[0x68f1e9]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld[0x614209]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_Z21mysql_execute_commandP3THD+0x1aa9)[0x619249]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN13sp_instr_stmt9exec_coreEP3THDPj+0x1c)[0x757b0c]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr+0xa7)[0x75a587]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x5aa)[0x75caaa]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN7sp_head7executeEP3THD+0x440)[0x75b460]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x4e1)[0x75d6f1]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_Z21mysql_execute_commandP3THD+0xbe9)[0x618389]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_Z11mysql_parseP3THDPKcjPS2_+0x22c)[0x61dcac]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x8f8)[0x61e5b8]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_Z10do_commandP3THD+0xc7)[0x61f1d7]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(handle_one_connection+0xe6)[0x6114f6]
/lib64/libpthread.so.0[0x2b711a08c2f7]
/lib64/libc.so.6(clone+0x6d)[0x2b711b576b6d]
[Falcon] Error: assertion (offset + length <= MAX_PHYSICAL_KEY_LENGTH) failed at line 148 in file IndexNode.h

--------------------------
So Falcon will try to restart and do recovery, however it still crash: 

/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(my_print_stacktrace+0x2e)[0x9ac93e]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(handle_segfault+0x33b)[0x6090eb]
/lib64/libpthread.so.0[0x2acd4ccf4e70]
/lib64/libpthread.so.0(raise+0x2d)[0x2acd4ccf4d4d]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN5Error5errorEPKcz+0xef)[0x825ebf]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN8DataPage12updateRecordEP7SectioniP6Streamjb+0xcf)[0x89a94f]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN7Section12updateRecordEiP6Streamjb+0x248)[0x8623b8]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN3Dbb12updateRecordEiiP6Streamjb+0x45)[0x81cc25]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN16SRLUpdateRecords4redoEv+0x1ab)[0x8863fb]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN9SerialLog7recoverEv+0x496)[0x86d8d6]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN8Database12openDatabaseEPKc+0xf6)[0x8188e6]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN10Connection11getDatabaseEPKcS1_P7Threads+0xcc)[0x80d25c]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN10Connection12openDatabaseEPKcS1_S1_S1_S1_P7Threads+0xa7)[0x80fbc7]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN15StorageDatabase17getOpenConnectionEv+0x58)[0x7da6d8]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN14StorageHandler10initializeEv+0x99)[0x7dd6a9]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_ZN16StorageInterface11falcon_initEPv+0x101)[0x7d2941]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0x38)[0x6f95d8]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld[0x7743aa]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(_Z11plugin_initPiPPci+0x889)[0x776de9]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld[0x60cf51]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(main+0x805)[0x60df75]
/lib64/libc.so.6(__libc_start_main+0xf4)[0x2acd4e1238b4]
/home/mysql/mysql-6.0-falcon-2682/libexec/mysqld(__gxx_personality_v0+0x269)[0x547369]
[Falcon] Error: assertion (idx->offset == 0 || (idx->offset >= indexEnd && idx->offset + idx->length <= dbb->pageSize)) failed at line 87 in file DataPage.cpp

How to repeat:
1. compile DBT2 with SP enabled. 
(check Makefile file that "DBC_FUNCTIONS = mysql" to make sure stored procedure is enabled)

2. ./run_mysql.sh -c 16 -w 10 -t 100 -u root -o /tmp/mysql.sock -e 

Then Falcon crash at the stage 2.
[7 Oct 2008 9:07] Xuekun Hu
I forgot to paste the Falcon configurations. 

  --skip_innodb \
  --default_storage_engine=Falcon \
  --falcon_io_threads=5 \
  --falcon_record_memory_max=650M \
  --falcon_page_cache_size=1650M \
  --falcon_page_size=4096 \
  --falcon_serial_log_buffers=100 \
[7 Oct 2008 11:55] Hakan Küçükyılmaz
Xuekun,

can you please retry with
  --falcon_page_size=8k

and see whether you get the same assertion?
[7 Oct 2008 11:59] Hakan Küçükyılmaz
Also, please try latest Falcon from BZR. We fixed this assertion lately
   Error: assertion (idx->offset == 0 || (idx->offset >= indexEnd && idx->offset +
idx->length <= dbb->pageSize)) failed at line 87 in file DataPage.cpp

https://code.launchpad.net/~mysql/mysql-server/mysql-6.0-falcon
[8 Oct 2008 6:10] Xuekun Hu
Hakan, I tried the latest code. Falcon still crash. But sometimes the assertion were at diffenet place. And sometimes recovery succeeded, sometimes recovery failed. I also tried different falcon_page_size (4k, 8k, 16k), crash as same.   

The assertion could be 
[Falcon] Error: assertion (key - (UCHAR*) indexNode < 14) failed at line 109 in file IndexNode.h
or
[Falcon] Error: assertion (offset + length <= MAX_PHYSICAL_KEY_LENGTH) failed at line 148 in file IndexNode.h
...
mysqld: my_new.cc:50: int __cxa_pure_virtual(): Assertion `"Pure virtual method called." == "Aborted"' failed.

 
And sometimes Falcon can identify the below query cause its crash. 

   select c_id from customer where  c_w_id = 1 and c_d_id = 2 and c_last = 'ABLEABLEOUGHT'  order by c_first asc limit 1
or 
   select c_id from customer where  c_w_id = 1 and c_d_id = 4 and c_last = 'PRESCALLYCALLY'  order by c_first asc limit 1;

And recovery failed at 

/home/mysql/mysql/libexec/mysqld(my_print_stacktrace+0x2e)[0x9b47ce]
/home/mysql/mysql/libexec/mysqld(handle_segfault+0x33b)[0x60b16b]
/lib64/libpthread.so.0[0x2b868e137e70]
/lib64/libpthread.so.0(raise+0x2d)[0x2b868e137d4d]
/home/mysql/mysql/libexec/mysqld(_ZN5Error5errorEPKcz+0xef)[0x82e5bf]
/home/mysql/mysql/libexec/mysqld(_ZN5Cache9fetchPageEP3Dbbi8PageType8LockType+0xf5)[0x80de45]
/home/mysql/mysql/libexec/mysqld(_ZN3Dbb11handoffPageEP3Bdbi8PageType8LockType+0x2a)[0x825fca]
/home/mysql/mysql/libexec/mysqld(_ZN13IndexRootPage17findInsertionLeafEP3DbbiP8IndexKeyij+0xbe)[0x83b27e]
/home/mysql/mysql/libexec/mysqld(_ZN13IndexRootPage13addIndexEntryEP3DbbiP8IndexKeyij+0x6f)[0x83b56f]
/home/mysql/mysql/libexec/mysqld(_ZN13IndexRootPage10indexMergeEP3DbbiP14SRLUpdateIndexj+0x4dd)[0x83c61d]
/home/mysql/mysql/libexec/mysqld(_ZN9SerialLog7recoverEv+0x496)[0x875546]
/home/mysql/mysql/libexec/mysqld(_ZN8Database12openDatabaseEPKc+0xf6)[0x821296]
/home/mysql/mysql/libexec/mysqld(_ZN10Connection11getDatabaseEPKcS1_P7Threads+0xcc)[0x815b3c]
/home/mysql/mysql/libexec/mysqld(_ZN10Connection12openDatabaseEPKcS1_S1_S1_S1_P7Threads+0xa7)[0x8184a7]
/home/mysql/mysql/libexec/mysqld(_ZN15StorageDatabase17getOpenConnectionEv+0x58)[0x7e2c08]
/home/mysql/mysql/libexec/mysqld(_ZN14StorageHandler10initializeEv+0x99)[0x7e5d19]
/home/mysql/mysql/libexec/mysqld(_ZN16StorageInterface11falcon_initEPv+0x159)[0x7ddb19]
/home/mysql/mysql/libexec/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0x38)[0x6fe198]
/home/mysql/mysql/libexec/mysqld[0x7795fa]
/home/mysql/mysql/libexec/mysqld(_Z11plugin_initPiPPci+0x8c9)[0x77c0e9]
/home/mysql/mysql/libexec/mysqld[0x60f42f]
/home/mysql/mysql/libexec/mysqld(main+0x805)[0x610535]
/lib64/libc.so.6(__libc_start_main+0xf4)[0x2b868f5668b4]
/home/mysql/mysql/libexec/mysqld(__gxx_personality_v0+0x271)[0x548c79]
[Falcon] Error: page 131238/1 wrong page type, expected 5 got 7

Thx, Xuekun
[8 Oct 2008 14:17] Kevin Lewis
Verified based on the ltest tests by Xuekun.

Ann, one of these asserts is the same as Bug#38130.
[16 Oct 2008 22:01] Kevin Lewis
Ann, The first crash is a duplicate of Bug#38130.  The second is during recovery after that.  If the recovery problem is directly due to 38130, then this can be marked as a duplicate.
[15 Dec 2008 23:41] Kevin Lewis
Hakan,  this one has been on the shelf for a while.  Can you re-verify that this occurs, and if so, which call stack is the problem?
[5 May 2009 13:09] Kevin Lewis
On Monday, May 04, 2009 10:48 PM, Kevin wrote; 
Xuekun, can you still reproduce Bug#39901?  There have been some related fixes in the last couple months.

On Tue, 05 May 2009 16:34:27 +0800, Xuekun wrote;

Great. The falcon crash is gone. I tested on the latest falcon tree (rev2697, 2009-04-28) with sp enabled.

And It is interesting to compare with and without SP of DBT2 performance. I found at lower concurrencies, with SP performance is lower than w/o SP performance, then with increasing the number of connections, with SP performance continue increase, then at higher concurrencies, its performance is greater than w/o sp performance.

100WH   Connections             8       16      32      64      128     256
w/o sp  24792.53                28360.72                26704.51        25670.40        24302.21        24756.44
w sp            8279.95                 9794.25                 13844.52        20264.57        27614.40        31555.89

10WH    Connections             8       16      32      64      128     256
w/o sp  41427.44        54097.19        54418.99        52233.47        49891.91        50202.14
w sp            33148.94        39251.66        44105.63        49326.23        60283.92        59840.30