Bug #45654 Falcon crashes when StorageInterface::decodeRecord() calling Field_string::store
Submitted: 22 Jun 2009 13:40 Modified: 26 May 2010 17:53
Reporter: Olav Sandstå Email Updates:
Status: Unsupported Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S2 (Serious)
Version:6.0.12-alpha OS:Linux
Assigned to: Olav Sandstå CPU Architecture:Any
Tags: F_RECOVERY

[22 Jun 2009 13:40] Olav Sandstå
Description:
When running the RQG test falcon_manyindexes the following crash occured when the test does the verification of the database after a successful recovery:

# 05:56:49 Verifying table: table100_falcon_key_pk_parts_2_int_autoinc; database: test
# 05:56:55 090619  5:56:55 - mysqld got signal 11 ;
# 05:56:55 This could be because you hit a bug. It is also possible that this binary
# 05:56:55 or one of the libraries it was linked against is corrupt, improperly built,
# 05:56:55 or misconfigured. This error can also be caused by malfunctioning hardware.
# 05:56:55 We will try our best to scrape up some info that will hopefully help diagnose
# 05:56:55 the problem, but since we have already crashed, something is definitely wrong
# 05:56:55 and this may fail.
# 05:56:55 
# 05:56:55 key_buffer_size=8384512
# 05:56:55 read_buffer_size=131072
# 05:56:55 max_used_connections=1
# 05:56:55 max_threads=151
# 05:56:55 thread_count=1
# 05:56:55 connection_count=1
# 05:56:55 It is possible that mysqld could use up to 
# 05:56:55 key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 337825 K
# 05:56:55 bytes of memory
# 05:56:55 Hope that's ok; if not, decrease some variables in the equation.
# 05:56:55 
# 05:56:55 thd: 0xb6fc700
# 05:56:55 Attempting backtrace. You can use the following information to find out
# 05:56:55 where mysqld died. If you see no messages after this, something went
# 05:56:55 terribly wrong...
# 05:56:55 Trying to get some variables.
# 05:56:55 Some pointers may be invalid and cause the dump to abort...
# 05:56:55 thd->query at 0xb79e408 = SELECT * FROM `test`.`table100_falcon_key_pk_parts_2_int_autoinc` FORCE INDEX (varchar_255_utf16_key) WHERE `varchar_255_utf16_key` >= '' OR `varchar_255_utf16_key` IS NULL
# 05:56:55 thd->thread_id=1
# 05:56:55 thd->killed=NOT_KILLED
# 05:56:55 The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
# 05:56:55 information that should help you find out what is causing the crash.
# 05:56:55 Writing a core file
DBD::mysql::st execute failed: Lost connection to MySQL server during query at lib/GenTest/Reporter/Recovery.pm line 207, <RDRFH> line 30.
# 05:56:55 Failing query is SELECT * FROM `test`.`table100_falcon_key_pk_parts_2_int_autoinc` FORCE INDEX (varchar_255_utf16_key) WHERE `varchar_255_utf16_key` >= '' OR `varchar_255_utf16_key` IS NULL.
# 05:56:55 Shutting down the server.
# 05:56:55 Test completed with failure status 104.

The call stack:

mysqld(my_print_stacktrace+0x32) [0x8837f5d]
mysqld(handle_segfault+0x2cd) [0x82c245d] [0xc41420]
mysqld(my_well_formed_len_mb+0x3d) [0x885279e]
mysqld(well_formed_copy_nchars(charset_info_st*, char*, unsigned int, charset_info_st*, char const*, unsigned int, unsigned int, char const**, char const**, char const**)+0x25c) [0x82b9b40]
mysqld(Field_string::store(char const*, unsigned int, charset_info_st*)+0x116) [0x82982d0]
mysqld(StorageInterface::decodeRecord(unsigned char*)+0x6e5) [0x8559dc9]
mysqld(StorageInterface::index_next(unsigned char*)+0x2ba) [0x855da7c]
mysqld(handler::read_range_next()+0xb2) [0x84082d2]
mysqld(ha_partition::handle_ordered_next(unsigned char*, bool)+0x77) [0x841436b]
mysqld(ha_partition::read_range_next()+0x73) [0x84145b9]
mysqld(handler::multi_range_read_next(char**)+0x6b) [0x84065a7]
mysqld(QUICK_RANGE_SELECT::get_next()+0x75) [0x83e815f]
mysqld [0x83ffe45]
mysqld(sub_select(JOIN*, st_join_table*, bool)+0x208) [0x83484dc]
mysqld [0x8354a41]
mysqld(JOIN::exec()+0x20fa) [0x836f5f0]
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*)+0x311) [0x836a199]
mysqld(handle_select(THD*, LEX*, select_result*, unsigned long)+0x1ec) [0x836f900]
mysqld [0x82d29d3]
mysqld(mysql_execute_command(THD*)+0x96e) [0x82d3aa6]
mysqld(mysql_parse(THD*, char const*, unsigned int, char const**)+0x22f) [0x82dc5df]
mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x859) [0x82dd761]
mysqld(do_command(THD*)+0x242) [0x82de9f2]
mysqld(handle_one_connection+0x11d) [0x82cb397]

How to repeat:
Seen once after running RQG test falcon_manyindexes.
[22 Jun 2009 20:18] Olav Sandstå
A more readable version of the call stack from the core file:

#3  0x082c268a in handle_segfault (sig=11) at mysqld.cc:2711
#4  <signal handler called>
#5  0x088600b8 in my_mb_wc_utf8mb4 (cs=0x8ba8740, pwc=0xa90984cc, s=0x0, 
    e=0x3fc "\217\003") at ctype-utf8.c:2116
#6  0x0885279e in my_well_formed_len_mb (cs=0x8ba8740, b=0x0, 
    e=0x3fc "\217\003", pos=255, error=0xa9098518) at ctype-mb.c:296
#7  0x082b9b40 in well_formed_copy_nchars (to_cs=0x8ba8740, 
    to=0xb7d6bc0 ' ' <repeats 200 times>..., to_length=1020, 
    from_cs=0x8ba8740, from=0x0, from_length=1020, nchars=255, 
    well_formed_error_pos=0xa9098588, cannot_convert_error_pos=0xa9098584, 
    from_end_pos=0xa9098580) at sql_string.cc:1016
#8  0x082982d0 in Field_string::store (this=0xb7db578, from=0x0, length=1047, 
    cs=0x8ba8740) at field.cc:6304
#9  0x08559dc9 in StorageInterface::decodeRecord (this=0xb7d61a8, 
    buf=0xb7d63b8 "����") at ha_falcon.cpp:3322
#10 0x0855da7c in StorageInterface::index_next (this=0xb7d61a8, 
    buf=0xb7d63b8 "����") at ha_falcon.cpp:1894
#11 0x084082d2 in handler::read_range_next (this=0xb7d61a8) at handler.cc:5104
#12 0x0841436b in ha_partition::handle_ordered_next (this=0xb7d3b40, 
    buf=0xb7d63b8 "����", is_next_same=false) at ha_partition.cc:4707
#13 0x084145b9 in ha_partition::read_range_next (this=0xb7d3b40)
    at ha_partition.cc:4275
#14 0x084065a7 in handler::multi_range_read_next (this=0xb7d3b40, 
    range_info=0xa9098840) at handler.cc:4325
#15 0x083e815f in QUICK_RANGE_SELECT::get_next (this=0xb729400)
    at opt_range.cc:8579
#16 0x083ffe45 in rr_quick (info=0xb7a71f4) at records.cc:322
#17 0x083484dc in sub_select (join=0xb7a1438, join_tab=0xb7a71b0, 
    end_of_records=false) at sql_select.cc:16303
#18 0x08354a41 in do_select (join=0xb7a1438, fields=0xb6fdae4, table=0x0, 
    procedure=0x0) at sql_select.cc:15844
#19 0x0836f5f0 in JOIN::exec (this=0xb7a1438) at sql_select.cc:2886
#20 0x0836a199 in mysql_select (thd=0xb6fc700, rref_pointer_array=0xb6fdb54, 
    tables=0xb79e7d8, wild_num=1, fields=@0xb6fdae4, conds=0xb79eff0, 
    og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, 
    select_options=2147764736, result=0xb79f0f8, unit=0xb6fd7b4, 
    select_lex=0xb6fda50) at sql_select.cc:3067
#21 0x0836f900 in handle_select (thd=0xb6fc700, lex=0xb6fd758, 
    result=0xb79f0f8, setup_tables_done_option=0) at sql_select.cc:310
#22 0x082d29d3 in execute_sqlcom_select (thd=0xb6fc700, all_tables=0xb79e7d8)
    at sql_parse.cc:4964
#23 0x082d3aa6 in mysql_execute_command (thd=0xb6fc700) at sql_parse.cc:2172
#24 0x082dc5df in mysql_parse (thd=0xb6fc700, 
    inBuf=0xb79e408 "SELECT * FROM `test`.`table100_falcon_key_pk_parts_2_int_autoinc` FORCE INDEX (varchar_255_utf16_key) WHERE `varchar_255_utf16_key` >= '' OR `varchar_255_utf16_key` IS NULL", length=172, found_semicolon=0xa9099e80)
    at sql_parse.cc:5979
#25 0x082dd761 in dispatch_command (command=COM_QUERY, thd=0xb6fc700, 
    packet=0xb792549 "�hyhyhyhymumuuyuywnwnxbxbggggmomobtbtepepgzgzsosobebexkxkv
hvhvtvtiyiynknkfcfctmtmkikiiiiimumuxnxnvyvyhahalwlwhrhrieieqaqakqkqozozqvqvlplpqqqqguguususbdbdsqsqwwwwrmrmapaplqlqiiiismsmjdjdkxkxhphphshswgw"..., 
    packet_length=172) at sql_parse.cc:1064
#26 0x082de9f2 in do_command (thd=0xb6fc700) at sql_parse.cc:746
#27 0x082cb397 in handle_one_connection (arg=0xb6fc700) at sql_connect.cc:1146
#28 0x0089a45b in pthread_join () from /lib/libpthread.so.0
#29 0x007f1c4e in sprofil () from /lib/libc.so.6
[22 Jun 2009 20:26] Olav Sandstå
Also from the core file: Here is the content of the dataStream object processed in StorageInterface::decodeRecord():

(gdb) print dataStream
$5 = {_vptr.EncodedDataStream = 0x89f27c8, stream = 0x0, 
  ptr = 0xa4e01b34 "\024J", 
  end = 0xa4e021ca '�' <repeats 14 times>, " )���\032ठ��\b@\a", 
  type = edsTypeInt32, scale = 0, bigInt = {_vptr.BigInt = 0x89f1fa8, 
    length = 0, scale = 0, neg = 0, words = {0, 0, 0, 0, 0, 0, 0, 0, 0, 0}}, 
  static lengths = '\0' <repeats 52 times>, "\001\002\003\004\005\006\a\b\001\002\003\004\005\006\a\b\t��������\000\001\002\003\004\005\006\a\b\000\001\002\003\004\005\006\a\b\000\001\002\003\004\005\006\a\b\000\001\002\003\004\000\001\002\003\004\005\006\a\b\t\n\v\f\r\016\017\020\021\022\023\024\025\026\027\030\031\032\033\034\035\036\037 !\"#$%&'\000\001\002\003\004\005\006\a\b\t\n\v\f\r\016\017\020\021\022\023\024\025\026\027\030\031\032\033\034\035\036\037 !\"#$%&'\000\001\002\003\004\000\001\002\003\004�", '\0' <repeats 55 times>, value = {
    integer32 = 1047, blobId = 1047, integer64 = 1047, 
    dbl = 5.1728673119578513e-321, string = {length = 1047, data = 0x0}}}

Seems like the string object does not have a data member (is NULL) while still the length is 1047.
[29 Jul 2009 8:56] Olav Sandstå
I have verified that it is possible to reproduce an (almost) identical crash using the database files from the initial crash report:

1. Start the database by doing recovery based on the original database files:

./sql/mysqld --datadir=/home/olav/mysql/develop/bug/bug45654/a1/vardirs/master-data --falcon_debug_mask=3 --core-file

2. Log on using mysql and do the following:

  mysql> use test;
  mysql> select * from table100_falcon_key_pk_parts_2_int_autoinc;

This causes Falcon to crash in the same place as in the original crash but on something that seems to be a different record.
[3 Aug 2009 9:32] Olav Sandstå
Note that it seems like the SQL query from the original bug report:

SELECT * FROM `table100_falcon_key_pk_parts_2_int_autoinc` FORCE INDEX (varchar_255_utf16_key) WHERE `varchar_255_utf16_key` >= '' OR `varchar_255_utf16_key` IS NULL;

does not trigger the crash when running it after having done recovery.
[4 Aug 2009 10:40] Olav Sandstå
A small correction to the last comment:

* When using a 64-bit compiled Falcon on Solaris 10 the crash does not happen when running the SQL statement from the original bug report (as reported in the previous comment)

* But after having compiled a 32-bit Falcon version for Linux the identical crash happens when running the SQL-statement from the original bug report.
[12 Aug 2009 9:50] Olav Sandstå
A simplified version of the query that triggers the crash is:

SELECT * FROM `table100_falcon_key_pk_parts_2_int_autoinc` WHERE `varchar_255_utf16_key` >= '';
[12 Aug 2009 13:04] Olav Sandstå
The crash occurs due to that the record being processed does not have the correct format. Up until the crash happens all records have the following format for the six first fields:

Field no:  Falcon type:    MySQL type:

        0. edsTypeOpaque   MYSQL_TYPE_VARCHAR
        1. edsTypeOpaque   MYSQL_TYPE_VARCHAR
        2. edsTypeInt32    MYSQL_TYPE_SET
        3. edsTypeInt32    MYSQL_TYPE_SET
        4. edsTypeOpaque   MYSQL_TYPE_STRING
        5. edsTypeOpaque   MYSQL_TYPE_STRING

For the record that causes the crash the format if:

Field no:  Falcon type:    MySQL type:

        0. edsTypeInt32
        1. edsTypeNull
        2. edsTypeInt32
        3. edsTypeBlob
        4. edsTypeInt32
        5. edsTypeInt32

The crash occurs when processing the last of these fields. The falcon data type edsTypeInt32 is attempted to be converted and stored in the MySQL Field object as a string.

The table definition looks like:

mysql> show columns from table100_falcon_key_pk_parts_2_int_autoinc;
+-----------------------+---------------------------------------------------------------------------------------------------------------+------+-----+---------+----------------+
| Field                 | Type                                                                                                          | Null | Key | Default | Extra          |
+-----------------------+---------------------------------------------------------------------------------------------------------------+------+-----+---------+----------------+
| varchar_255_ucs2_key  | varchar(255)                                                                                                  | YES  | MUL | NULL    |                | 
| varchar_255_ucs2      | varchar(255)                                                                                                  | YES  |     | NULL    |                | 
| set_utf16_key         | set('','','','','','','','','','','','','','','','','','','','','','','','','','')                            | YES  | MUL | NULL    |                | 
| set_utf8_key          | set('a','b','c','d','e','f','g','h','i','j','k','l','m','n','o','p','q','r','s','t','u','v','w','x','y','z')  | YES  | MUL | NULL    |                | 
| char_255_utf8_key     | char(255)                                                                                                     | YES  | MUL | NULL    |                | 
| char_255_utf8         | char(255)                                                                                                     | YES  |     | NULL    |                | 
| set_utf16             | set('','','','','','','','','','','','','','','','','','','','','','','','','','')                            | YES  |     | NULL    |                | 
| enum_utf16            | enum('','','','','','','','','','','','','','','','','','','','','','','','','','')                           | YES  |     | NULL    |                | 
| varchar_255_utf16_key | varchar(255)                                                                                                  | YES  | MUL | NULL    |                | 
| enum_ucs2_key         | enum('','','','','','','','','','','','','','','','','','','','','','','','','','')                           | YES  | MUL | NULL    |                | 
| longtext_utf16        | longtext                                                                                                      | YES  |     | NULL    |                | 
| char_255_utf16        | char(255)                                                                                                     | YES  |     | NULL    |                | 
| char_255_utf16_key    | char(255)                                                                                                     | YES  | MUL | NULL    |                | 
| enum_utf8_key         | enum('a','b','c','d','e','f','g','h','i','j','k','l','m','n','o','p','q','r','s','t','u','v','w','x','y','z') | YES  | MUL | NULL    |                | 
| set_ucs2              | set('','','','','','','','','','','','','','','','','','','','','','','','','','')                            | YES  |     | NULL    |                | 
| varchar_255_utf16     | varchar(255)                                                                                                  | YES  |     | NULL    |                | 
| enum_utf8             | enum('a','b','c','d','e','f','g','h','i','j','k','l','m','n','o','p','q','r','s','t','u','v','w','x','y','z') | YES  |     | NULL    |                | 
| set_utf8              | set('a','b','c','d','e','f','g','h','i','j','k','l','m','n','o','p','q','r','s','t','u','v','w','x','y','z')  | YES  |     | NULL    |                | 
| char_255_ucs2_key     | char(255)                                                                                                     | YES  | MUL | NULL    |                | 
| enum_ucs2             | enum('','','','','','','','','','','','','','','','','','','','','','','','','','')                           | YES  |     | NULL    |                | 
| varchar_255_utf8_key  | varchar(255)                                                                                                  | YES  | MUL | NULL    |                | 
| pk                    | int(11)                                                                                                       | NO   | PRI | NULL    | auto_increment | 
| longtext_ucs2         | longtext                                                                                                      | YES  |     | NULL    |                | 
| enum_utf16_key        | enum('','','','','','','','','','','','','','','','','','','','','','','','','','')                           | YES  | MUL | NULL    |                | 
| set_ucs2_key          | set('','','','','','','','','','','','','','','','','','','','','','','','','','')                            | YES  | MUL | NULL    |                | 
| longtext_utf8         | longtext                                                                                                      | YES  |     | NULL    |                | 
| varchar_255_utf8      | varchar(255)                                                                                                  | YES  |     | NULL    |                | 
| char_255_ucs2         | char(255)                                                                                                     | YES  |     | NULL    |                | 
+-----------------------+---------------------------------------------------------------------------------------------------------------+------+-----+---------+----------------+
28 rows in set (0.00 sec)

mysql>
[8 Sep 2009 13:48] Olav Sandstå
Changing the Falcon code so that this does not lead to a crash but instead prints out the content of the found record shows the following:

1. The format of the record stored in Falcon does not confirm with the format expected by the MySQL server (as shown in the previous comment added to this bug report).

2. The format of the retrieved record instead confirms well with the record format of the second table that is stored in Falcon (table name: table100_falcon_int_autoinc). 

3. The query returns four records that where the record format of the stored record does not confirm with the table's record format but instead corresponds to the record format of the second table (in total the query returns 2464 records).
[8 Sep 2009 13:51] Olav Sandstå
If I remove the where clause from the query to make it less likely that an index is used for executing the table:

  SELECT * FROM `table100_falcon_key_pk_parts_2_int_autoinc`;

The result is:

2855 records returned. Out of these 6 records does not confirm with the table's correct record format but corresponds well with the record format of   the second table stored in Falcon.

This might indicate that this table contains records that should not be there but instead is part of the second table.