MySQL Bugs: #43562: Crash when creating a Falcon table after upgrade from 6.0.9 to 6.0.10

Bug #43562	Crash when creating a Falcon table after upgrade from 6.0.9 to 6.0.10
Submitted:	11 Mar 2009 13:22	Modified:	15 May 2009 15:54
Reporter:	Vemund Østgaard	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Falcon storage engine	Severity:	S1 (Critical)
Version:	6.0.10	OS:	Linux (2.6.9-34.ELsmp64 64-bit)
Assigned to:	Vladislav Vaintroub	CPU Architecture:	Any
Tags:	F_STARTUP

Description:
A test of upgrade from 6.0.9 to 6.0.10 fails with a server crash when it is attempting to create a Falcon table after the upgrade.

Upgrade is done by restarting the 6.0.9 server with a 6.0.10 version and the same database directory and then running the mysql_upgrade command.

Shortly after upgrade the test tries to create this table: 

CREATE TABLE falcon_table2 (
col1 CHAR(1) CHARACTER SET utf8,
col2 CHAR(1) CHARACTER SET utf8) ENGINE = FALCON;

This fails with: 

failed: 2013: Lost connection to MySQL server during query

and the server has crashed.

The master.err file shows:

terminate called after throwing an instance of 'SQLError'
090311 13:54:53 - 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=1048576
read_buffer_size=131072
max_used_connections=2
max_threads=151
thread_count=2
connection_count=2
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 60622 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x2083f80
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...
stack_bottom = 0x4dcd81a0 thread_stack 0x40000
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(my_print_stacktrace+0x29) [0xac3839]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(handle_segfault+0x33b) [0x6518cb]
/lib64/tls/libpthread.so.0 [0x360d30c420]
/lib64/tls/libc.so.6(gsignal+0x3d) [0x360ca2e2ed]
/lib64/tls/libc.so.6(abort+0xfe) [0x360ca2fa3e]
/usr/lib64/libstdc++.so.6(__gnu_cxx::__verbose_terminate_handler()+0xc8) [0x360dfb1138]
/usr/lib64/libstdc++.so.6 [0x360dfaf166]
/usr/lib64/libstdc++.so.6 [0x360dfaf193]
/usr/lib64/libstdc++.so.6(__cxa_rethrow+0x41) [0x360dfaf2e1]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(Database::prepareStatement(Connection*, char const*)+0x92) [0x899522]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(Connection::prepareStatement(char const*)+0x2a) [0x8945da]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(StorageTableShare::lookupPathName()+0x66) [0x862c86]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(StorageTableShare::tableExists()+0x19) [0x862ff9]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(StorageHandler::createTable(char const*, char const*, bool)+0x70) [0x860920]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(StorageInterface::create(char const*, TABLE*, st_ha_create_information*)+0x88) [0x852488]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(ha_create_table(THD*, char const*, char const*, char const*, st_ha_create_information*, bool)+0x1fc) [0x75965c]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(rea_create_table(THD*, char const*, char const*, char const*, st_ha_create_information*, List<Create_field>&, unsigned int, st_key*, handler*)+0x12b) [0x7192fb]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(mysql_create_table_no_lock(THD*, char const*, char const*, st_ha_create_information*, Alter_info*, bool, unsigned int)+0x5d9) [0x76c619]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(mysql_create_table(THD*, char const*, char const*, st_ha_create_information*, Alter_info*, bool, unsigned int)+0x8f) [0x76dd7f]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(mysql_execute_command(THD*)+0x4f3e) [0x666e2e]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(mysql_parse(THD*, char const*, unsigned int, char const**)+0x36e) [0x66735e]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x859) [0x668009]
/home/vo136787/mysql/mysql-6.0.10-alpha-linux-x86_64-glibc23/bin/mysqld(handle_one_connection+0x1a9) [0x65afb9]
/lib64/tls/libpthread.so.0 [0x360d30610a]
/lib64/tls/libc.so.6(__clone+0x73) [0x360cac6003]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x208f2f8 = CREATE TABLE falcon_table2 (
col1 CHAR(1) CHARACTER SET utf8,
col2 CHAR(1) CHARACTER SET utf8) ENGINE = FALCON
thd->thread_id=2
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.
Writing a core file

I will upload a separate file with the backtrace from all threads taken from the corefile.

How to repeat:
What I have done:

1. Start 6.0.9 server
2. Create a schema
3. Stop server and start it again with version 6.0.10
4. Create a Falcon table: 

REATE TABLE falcon_table2 (
col1 CHAR(1) CHARACTER SET utf8,
col2 CHAR(1) CHARACTER SET utf8) ENGINE = FALCON;

The crash is 100% reproducible in my test environment. I do not get a crash if I create the same table with MyISAM instead of Falcon, or if I use mysqldump to upgrade the database (dump in 6.0.9 and load into 6.0.10).

trace from all threads taken from corefile

Attachment: threadtrace (application/octet-stream, text), 18.89 KiB.

much simpler test case:

1. start any 6.0.x server less than 6.0.10 with fresh db(I checked with 6.0.8 and 6.0.9):
2. mysql -uroot -s /tmp/mysql.sock -e'create table t1(a int) engine falcon'
3. mysqladmin shut -uroot -s /tmp/mysql.sock 
4. start 6.0.10 server with the same database 
5. mysql -uroot -s /tmp/mysql.sock -e'show create table t1' -> server crashes

...
terminate called after throwing an instance of 'SQLError'
090320 17:33:31 - mysqld got signal 6 ;
...

./bin/mysqld(my_print_stacktrace+0x29) [0xac3839]
./bin/mysqld(handle_segfault+0x33b) [0x6518cb]
/lib64/libpthread.so.0 [0x2b1a125ec140]
/lib64/libc.so.6(gsignal+0x35) [0x2b1a12dcdaa5]
/lib64/libc.so.6(abort+0x110) [0x2b1a12dcee60]
/usr/lib64/libstdc++.so.6(__gnu_cxx::__verbose_terminate_handler()+0x114) [0x2b1a128b9d24]
/usr/lib64/libstdc++.so.6 [0x2b1a128b7e56]
/usr/lib64/libstdc++.so.6 [0x2b1a128b7e83]
/usr/lib64/libstdc++.so.6(__cxa_rethrow+0x45) [0x2b1a128b7f05]
./bin/mysqld(Database::prepareStatement(Connection*, char const*)+0x92) [0x899522]
./bin/mysqld(Connection::prepareStatement(char const*)+0x2a) [0x8945da]
./bin/mysqld(StorageTableShare::load()+0x6c) [0x862ebc]
./bin/mysqld(StorageTableShare::findDatabase()+0x20) [0x863130]
./bin/mysqld(StorageHandler::getStorageConnection(StorageTableShare*, THD*, int, OpenOption)+0x1d2) [0x8607a2]
./bin/mysqld(StorageInterface::open(char const*, int, unsigned int)+0x109) [0x851889]
./bin/mysqld(handler::ha_open(TABLE*, char const*, int, int)+0x3f) [0x75478f]
./bin/mysqld(open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, open_table_mode)+0x5d7) [0x6a7897]
./bin/mysqld(open_table(THD*, TABLE_LIST*, st_mem_root*, enum_open_table_action*, unsigned int)+0xa9c) [0x6a2bec]
./bin/mysqld(open_tables(THD*, TABLE_LIST**, unsigned int*, unsigned int)+0x48c) [0x6a37cc]
./bin/mysqld(open_normal_and_derived_tables(THD*, TABLE_LIST*, unsigned int)+0x1e) [0x6a3ade]
./bin/mysqld(mysqld_list_fields(THD*, TABLE_LIST*, char const*)+0x22) [0x783ed2]
./bin/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x74d) [0x667efd]
./bin/mysqld(handle_one_connection+0x1a9) [0x65afb9]
/lib64/libpthread.so.0 [0x2b1a125e5193]
/lib64/libc.so.6(__clone+0x6d) [0x2b1a12e5d45d]

(gdb) bt
#0  0x00002b1a125e94c5 in pthread_kill () from /lib64/libpthread.so.0
#1  0x00000000006518fe in handle_segfault (sig=6) at mysqld.cc:2689
#2  <signal handler called>
#3  0x00002b1a12dcdaa5 in raise () from /lib64/libc.so.6
#4  0x00002b1a12dcee60 in abort () from /lib64/libc.so.6
#5  0x00002b1a128b9d24 in __gnu_cxx::__verbose_terminate_handler () from /usr/lib64/libstdc++.so.6
#6  0x00002b1a128b7e56 in std::set_unexpected () from /usr/lib64/libstdc++.so.6
#7  0x00002b1a128b7e83 in std::terminate () from /usr/lib64/libstdc++.so.6
#8  0x00002b1a128b7f05 in __cxa_rethrow () from /usr/lib64/libstdc++.so.6
#9  0x0000000000899522 in Database::prepareStatement (this=0x2aaaab2abbb8, connection=0x2aaaab4ceb38, sqlStr=0xc29420 "select given_schema_name,given_table_name,effective_schema_name,effective_table_name,tablespace_name from falcon.tables where pathname=?") at Database.cpp:1136
#10 0x00000000008945da in Connection::prepareStatement (this=0x2aaaab4ceb38, sqlString=<value optimized out>) at Connection.cpp:234
#11 0x0000000000862ebc in StorageTableShare::load (this=0x2aaaab4d0da0) at StorageTableShare.cpp:637
#12 0x0000000000863130 in StorageTableShare::findDatabase (this=0x5bca) at StorageTableShare.cpp:752
#13 0x00000000008607a2 in StorageHandler::getStorageConnection (this=0x2aaaab2ab040, tableShare=0x2aaaab4d0da0, mySqlThread=0x1a70680, mySqlThdId=1, createFlag=OpenDatabase) at StorageHandler.cpp:708
#14 0x0000000000851889 in StorageInterface::open (this=0x1abcff8, name=0x1a74d00 "./test/t1", mode=<value optimized out>, test_if_locked=<value optimized out>) at ha_falcon.cpp:520
#15 0x000000000075478f in handler::ha_open (this=0x5bca, table_arg=<value optimized out>, name=0x1a74d00 "./test/t1", mode=2, test_if_locked=1) at handler.cc:2037
#16 0x00000000006a7897 in open_table_from_share (thd=0x1a70680, share=0x1a749b8, alias=<value optimized out>, db_stat=0, prgflag=44, ha_open_flags=0, outparam=0x1abc740, open_mode=OTM_OPEN) at table.cc:2022
#17 0x00000000006a2bec in open_table (thd=0x1a70680, table_list=0x4708eb10, mem_root=0x4708e380, action=0x4708e3d8, flags=0) at sql_base.cc:2746
#18 0x00000000006a37cc in open_tables (thd=0x1a70680, start=0x4708e428, counter=0x4708e43c, flags=0) at sql_base.cc:3739
#19 0x00000000006a3ade in open_normal_and_derived_tables (thd=0x5bca, tables=0x4708eb10, flags=4294967295) at sql_base.cc:4237
#20 0x0000000000783ed2 in mysqld_list_fields (thd=0x5bca, table_list=0x5be4, wild=0x1acc6c0 "") at sql_show.cc:681
#21 0x0000000000667efd in dispatch_command (command=<value optimized out>, thd=0x1a70680, packet=0x1ac4661 "t1", packet_length=4266899871) at sql_parse.cc:1131
#22 0x000000000065afb9 in handle_one_connection (arg=<value optimized out>) at sql_connect.cc:1146
#23 0x00002b1a125e5193 in start_thread () from /lib64/libpthread.so.0
#24 0x00002b1a12e5d45d in clone () from /lib64/libc.so.6

See also Bug#43868

Lars-Erik, Since issue has major exposure, Can you reproduce it right away and determine what code change is at fault.  I suspect it is one of Vlad's changes to the serial log or index.  But we need to find out and provide a fix before the next clone-off if we can.

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/71161

3093 Vladislav Vaintroub	2009-04-02
      Bug#43562 Crash when creating a Falcon table after upgrade from 6.0.9 to 6.0.10
      
      The reason for the crash is that generation of multisegment key format was changed 
      slightly as side-effect of fix for 42136. The new format worked ok with new databases
      but not with the old ones. 
      
      In this particular case, the error comes from Falcon's internal security mechanism. 
      Due to changed index format, a query in Falcon's data dictionary unexpectedly returned 
      an empty result set. This was interpreted was missing privilege to create tables.
      Exception (security error) was thrown and not caught.
      
      Fix:
      
      - Define new minor ODS version 2.4 for databases with changed multisegment index.
      - During the start, perform a check for 2.4 format(MySQL 6.10 would correspond to 
      2.4 Falcon)
      
      When building multisegment indexes, regard the ODS version and create different 
      indexes in 2.3  and 2.4.
     @ storage/falcon/Database.cpp
        Special check for ODS version 2.3 (it  can be in fact 2.4)
     @ storage/falcon/Database.h
        Increase ODS_MINOR_VERSION
     @ storage/falcon/Dbb.cpp
        New function to upgrade minor ODS version the fly
     @ storage/falcon/Dbb.h
        New function to upgrade minor ODS version the fly
     @ storage/falcon/Index.cpp
        Depending on ODS version, build multisegment key in either 2.3 or 2.4 format.

Patch looks good.  We need our QA group to create backward compatibility tests from now on.

Pushed into 6.0.11-alpha (revid:hky@sun.com-20090415164923-9arx29ye5pzxd4zf) (version source revid:kevin.lewis@sun.com-20090402193456-00z3sz4w7i520slw) (merge vers: 6.0.11-alpha) (pib:6)

A note has been added to the 6.0.11 changelog: 

Upgrading MySQL to 6.0.10 from 6.0.9 when using Falcon tables and the mysql_upgrade tool would cause mysqld to crash during start up.